You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cocoon.apache.org by Carsten Ziegeler <cz...@sundn.de> on 2001/08/07 12:35:42 UTC
[C2]: Performance and logging
Hi,
I know that we had this discussion some time ago, with no real solution,
so I thought: why not start it again?
Looking at the way logging is performed in cocoon 2, I think this is
not very fast. Here an example:
<CODE>
getLogger().debug("Creating new Templates in " + this + " for " +
this.inputSource.getSystemId());
</CODE>
Even if the priority debug is disabled, the method getLogger() (from
AbstractLoggable) is called
returning the logger, the expensive string concatenation is performed and
the debug() method
of the logger is called. And these steps are done for every debug message!
We should change two things here:
a) Replace the getLogger() call with the use of an instance variable logger.
This requires to make an own AbstractLoggable class which offers the
logger as an instance
variable and not via a method.
b) Before logging testing the priority.
So the example above should read:
<CODE>
if (this.logger.isDebugEnabled() == true) {
this.logger.debug("Creating new Templates in " + this + " for " +
this.inputSource.getSystemId());
}
</CODE>
Comments? Ideas? Suggestions? Volunteers?
Carsten
Open Source Group sunShine - b:Integrated
================================================================
Carsten Ziegeler, S&N AG, Klingenderstrasse 5, D-33100 Paderborn
www.sundn.de mailto: cziegeler@sundn.de
================================================================
---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org
AW: [C2]: Performance and logging
Posted by Carsten Ziegeler <cz...@sundn.de>.
> Berin Loritsch wrote:
>
> Carsten Ziegeler wrote:
> >
> > Hi,
> >
> > I know that we had this discussion some time ago, with no real solution,
> > so I thought: why not start it again?
> >
> > Looking at the way logging is performed in cocoon 2, I think this is
> > not very fast. Here an example:
> >
> > <CODE>
> > getLogger().debug("Creating new Templates in " + this + " for " +
> > this.inputSource.getSystemId());
> > </CODE>
>
>
> You can use the following construct:
>
> <CODE>
> if ( getLogger().isDebugEnabled() ) {
> getLogger().debug("Creating new Templates in " + this + " for " +
> this.inputSource.getSystemId());
> }
> </CODE>
>
> That way your string concatenation only happens when necessary.
>
> You can also getLogger() at the beginning of the method so that the method
> is only called once:
>
> <CODE>
> private void myMethod() {
> Logger log = getLogger();
>
> //do some stuff
>
> if (log.isDebugEnabled() ) {
> log.debug("Create" + " " + "Expensive" + " " + String + " " +
> "Concatenations.");
> }
> }
> </CODE>
>
Yes, this reduces the overhead a little bit, but I still have it in every
method although the logger is only set once for each object.
> > Even if the priority debug is disabled, the method getLogger() (from
> > AbstractLoggable) is called
> > returning the logger, the expensive string concatenation is
> performed and
> > the debug() method
> > of the logger is called. And these steps are done for every
> debug message!
> >
> > We should change two things here:
> > a) Replace the getLogger() call with the use of an instance
> variable logger.
> > This requires to make an own AbstractLoggable class which offers the
> > logger as an instance
> > variable and not via a method.
>
> When you extend AbstractLoggable, the instance variable is called
> "m_logger".
> the getLogger() is a convenience so that you are spared the implementation
> details of class. If the instance variable name was changed (as
> there is no
> contract to enforce this name to be the same) it will not break
> your code if
> you use the getLogger() method. It only needs to be called once
> in a method
> though.
>
That's the reason why I thought writing an own AbstractLoggable class
which enforces the name of the instance variable to be e.g. logger
or something like that.
> > b) Before logging testing the priority.
> >
> > So the example above should read:
> >
> > <CODE>
> > if (this.logger.isDebugEnabled() == true) {
> > this.logger.debug("Creating new Templates in " + this + " for " +
> > this.inputSource.getSystemId());
> > }
> > </CODE>
>
> You shouldn't use the "== true" because that is not only implied,
> but violates
> Sun's coding standards. It's a boolean already.
>
Well, there are so many coding standards and consulting java beginners
for more than 3 years now, I found out that it is for beginners more
readable to add the "== true" or "== false" to boolean expressions.
But fortunately this is not the topic of this email...
Carsten
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
> For additional commands, email: cocoon-dev-help@xml.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org
Re: [C2]: Performance and logging
Posted by Berin Loritsch <bl...@apache.org>.
Carsten Ziegeler wrote:
>
> Hi,
>
> I know that we had this discussion some time ago, with no real solution,
> so I thought: why not start it again?
>
> Looking at the way logging is performed in cocoon 2, I think this is
> not very fast. Here an example:
>
> <CODE>
> getLogger().debug("Creating new Templates in " + this + " for " +
> this.inputSource.getSystemId());
> </CODE>
You can use the following construct:
<CODE>
if ( getLogger().isDebugEnabled() ) {
getLogger().debug("Creating new Templates in " + this + " for " +
this.inputSource.getSystemId());
}
</CODE>
That way your string concatenation only happens when necessary.
You can also getLogger() at the beginning of the method so that the method
is only called once:
<CODE>
private void myMethod() {
Logger log = getLogger();
//do some stuff
if (log.isDebugEnabled() ) {
log.debug("Create" + " " + "Expensive" + " " + String + " " +
"Concatenations.");
}
}
</CODE>
> Even if the priority debug is disabled, the method getLogger() (from
> AbstractLoggable) is called
> returning the logger, the expensive string concatenation is performed and
> the debug() method
> of the logger is called. And these steps are done for every debug message!
>
> We should change two things here:
> a) Replace the getLogger() call with the use of an instance variable logger.
> This requires to make an own AbstractLoggable class which offers the
> logger as an instance
> variable and not via a method.
When you extend AbstractLoggable, the instance variable is called "m_logger".
the getLogger() is a convenience so that you are spared the implementation
details of class. If the instance variable name was changed (as there is no
contract to enforce this name to be the same) it will not break your code if
you use the getLogger() method. It only needs to be called once in a method
though.
> b) Before logging testing the priority.
>
> So the example above should read:
>
> <CODE>
> if (this.logger.isDebugEnabled() == true) {
> this.logger.debug("Creating new Templates in " + this + " for " +
> this.inputSource.getSystemId());
> }
> </CODE>
You shouldn't use the "== true" because that is not only implied, but violates
Sun's coding standards. It's a boolean already.
---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org
Re: [C2]: Performance and logging
Posted by giacomo <gi...@apache.org>.
On Tue, 7 Aug 2001, Carsten Ziegeler wrote:
> Hi,
>
> I know that we had this discussion some time ago, with no real solution,
> so I thought: why not start it again?
>
> Looking at the way logging is performed in cocoon 2, I think this is
> not very fast. Here an example:
>
> <CODE>
> getLogger().debug("Creating new Templates in " + this + " for " +
> this.inputSource.getSystemId());
> </CODE>
>
> Even if the priority debug is disabled, the method getLogger() (from
> AbstractLoggable) is called
> returning the logger, the expensive string concatenation is performed and
> the debug() method
> of the logger is called. And these steps are done for every debug message!
>
> We should change two things here:
> a) Replace the getLogger() call with the use of an instance variable logger.
> This requires to make an own AbstractLoggable class which offers the
> logger as an instance
> variable and not via a method.
-1 I don't see you'll gain any performance. As the getLogger method of
the AbstractLoggable is final it is subject for inlining the logger
reference.
> b) Before logging testing the priority.
I had this issue many month ago. So I've tested a C2 version which had
NO logging statements at all in the code against a normal one at
loglevel DEBUG. The speed difference was about 5-7% which will mostly
result because of the I/O operations during the logging. At loglevel
FATAL_ERROR there was no significant difference. I confess that since
that time there has been more logging statement introduced and of course
complex string manipulations to create a log message should be enclosed
in snippets like below. But sure I can easily give a +1 for this.
Giacomo
>
> So the example above should read:
>
> <CODE>
> if (this.logger.isDebugEnabled() == true) {
> this.logger.debug("Creating new Templates in " + this + " for " +
> this.inputSource.getSystemId());
> }
> </CODE>
>
> Comments? Ideas? Suggestions? Volunteers?
>
>
> Carsten
>
> Open Source Group sunShine - b:Integrated
> ================================================================
> Carsten Ziegeler, S&N AG, Klingenderstrasse 5, D-33100 Paderborn
> www.sundn.de mailto: cziegeler@sundn.de
> ================================================================
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
> For additional commands, email: cocoon-dev-help@xml.apache.org
>
>
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org
AW: [C2]: Performance and logging
Posted by Carsten Ziegeler <cz...@sundn.de>.
> Vadim Gritsenko wrote:
>
> > -----Original Message-----
> > From: Carsten Ziegeler [mailto:cziegeler@sundn.de]
> > Sent: Tuesday, August 07, 2001 6:36 AM
> > To: Cocoon-Dev@Xml. Apache. Org
> > Subject: [C2]: Performance and logging
> >
> >
> > Hi,
> >
> > I know that we had this discussion some time ago, with no real solution,
> > so I thought: why not start it again?
> >
> > Looking at the way logging is performed in cocoon 2, I think this is
> > not very fast. Here an example:
> >
> > <CODE>
> > getLogger().debug("Creating new Templates in " + this + " for " +
> > this.inputSource.getSystemId());
> > </CODE>
> >
> > Even if the priority debug is disabled, the method getLogger() (from
> > AbstractLoggable) is called returning the logger,
>
> IIRC, argument here was that getLogger() method is final and should
> be inlined by hotspot/JIT engine...
>
Yes, but looking through the LogKit website, there is the hint to
make the test itself and do not rely on this hotspot feature.
I find it very dangerous to rely on a special jvm implementation when
it comes to performance.
>
> > the expensive string concatenation is performed and the debug() method
> > of the logger is called. And these steps are done for every
> debug message!
> >
>
> Same thing here: if method is inlined, first is...enabled() check
> should occur.
> I'm not sure however that this occurs in reality.
>
> Carssten,
> Did you try to coment out all debug messages to check the difference in
> processing time?
>
No, I didn't have the time right now as there are some many log statements
and I think one should remove/change all when testing.
Did anyone else do this?
Carsten
>
> Vadim
>
> > We should change two things here:
> > a) Replace the getLogger() call with the use of an instance
> variable logger.
> > This requires to make an own AbstractLoggable class which offers the
> > logger as an instance
> > variable and not via a method.
> > b) Before logging testing the priority.
> >
> > So the example above should read:
> >
> > <CODE>
> > if (this.logger.isDebugEnabled() == true) {
> > this.logger.debug("Creating new Templates in " + this + " for " +
> > this.inputSource.getSystemId());
> > }
> > </CODE>
> >
> > Comments? Ideas? Suggestions? Volunteers?
> >
> >
> > Carsten
> >
> > Open Source Group sunShine - b:Integrated
> > ================================================================
> > Carsten Ziegeler, S&N AG, Klingenderstrasse 5, D-33100 Paderborn
> > www.sundn.de mailto: cziegeler@sundn.de
> > ================================================================
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
> For additional commands, email: cocoon-dev-help@xml.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org
RE: [C2]: Performance and logging
Posted by Vadim Gritsenko <vg...@hns.com>.
> -----Original Message-----
> From: Carsten Ziegeler [mailto:cziegeler@sundn.de]
> Sent: Tuesday, August 07, 2001 6:36 AM
> To: Cocoon-Dev@Xml. Apache. Org
> Subject: [C2]: Performance and logging
>
>
> Hi,
>
> I know that we had this discussion some time ago, with no real solution,
> so I thought: why not start it again?
>
> Looking at the way logging is performed in cocoon 2, I think this is
> not very fast. Here an example:
>
> <CODE>
> getLogger().debug("Creating new Templates in " + this + " for " +
> this.inputSource.getSystemId());
> </CODE>
>
> Even if the priority debug is disabled, the method getLogger() (from
> AbstractLoggable) is called returning the logger,
IIRC, argument here was that getLogger() method is final and should
be inlined by hotspot/JIT engine...
> the expensive string concatenation is performed and the debug() method
> of the logger is called. And these steps are done for every debug message!
>
Same thing here: if method is inlined, first is...enabled() check should occur.
I'm not sure however that this occurs in reality.
Carssten,
Did you try to coment out all debug messages to check the difference in
processing time?
Vadim
> We should change two things here:
> a) Replace the getLogger() call with the use of an instance variable logger.
> This requires to make an own AbstractLoggable class which offers the
> logger as an instance
> variable and not via a method.
> b) Before logging testing the priority.
>
> So the example above should read:
>
> <CODE>
> if (this.logger.isDebugEnabled() == true) {
> this.logger.debug("Creating new Templates in " + this + " for " +
> this.inputSource.getSystemId());
> }
> </CODE>
>
> Comments? Ideas? Suggestions? Volunteers?
>
>
> Carsten
>
> Open Source Group sunShine - b:Integrated
> ================================================================
> Carsten Ziegeler, S&N AG, Klingenderstrasse 5, D-33100 Paderborn
> www.sundn.de mailto: cziegeler@sundn.de
> ================================================================
>
---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org