Loggers, final classes and performance

[Vincent Massol <vm...@octo.com>]

Hi,

I need your expert advice here. The Log4JLogger class is declared as a final
class. In my code, I use :

Logger logger = new Log4JLogger(
    Category.getInstance(targetName));

This is used in a generic method that is called to automatically log entries
and exits of methods, so it is executed every time there is a log to be made
for an entry/exit. It is thus called very often.

I'd like to know if it has any performance issue. More specifically, I'd
like to know if the final keyword helps for performance (as it does for
final methods which are inlined) : I guess that even with the final keyword,
there is always a new object instanciated in memory ...

So, I also guess that simply writing :

Category category = Category.getInstance(targetName);

would be more performant ?

Another solution would be to have a hashmap of all loggers and check in the
hashmap whether the logger for a given targetName already exist and then use
that logger if it does. However, the additional work (putting the instances
in the hash, possibly with synchronisation (argh!), then doing an "if" and
then fetching the logger from the hash) might overall be more costly that
instanciating a new object.

What do you think ? Any idea ?
Thanks
-Vincent



--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>

Re: Loggers, final classes and performance

[Berin Loritsch <bl...@apache.org>]

Vincent Massol wrote:

> Hi,
> 
> I need your expert advice here. The Log4JLogger class is declared as a final
> class. In my code, I use :
> 
> Logger logger = new Log4JLogger(
>     Category.getInstance(targetName));
> 
> This is used in a generic method that is called to automatically log entries
> and exits of methods, so it is executed every time there is a log to be made
> for an entry/exit. It is thus called very often.
> 
> I'd like to know if it has any performance issue. More specifically, I'd
> like to know if the final keyword helps for performance (as it does for
> final methods which are inlined) : I guess that even with the final keyword,
> there is always a new object instanciated in memory ...


The final declaration does help alot.



> So, I also guess that simply writing :
> 
> Category category = Category.getInstance(targetName);
> 
> would be more performant ?


By a couple nano/pico seconds



> Another solution would be to have a hashmap of all loggers and check in the
> hashmap whether the logger for a given targetName already exist and then use
> that logger if it does. However, the additional work (putting the instances
> in the hash, possibly with synchronisation (argh!), then doing an "if" and
> then fetching the logger from the hash) might overall be more costly that
> instanciating a new object.


Today's JREs are optimized to deal with small final classes.  The garbage
collection overhead for these objeccts is actually _less_ than the overhead
of caching them.


-- 

"They that give up essential liberty to obtain a little temporary safety
  deserve neither liberty nor safety."
                 - Benjamin Franklin


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>

Re: Loggers, final classes and performance

[Peter Donald <pe...@apache.org>]

On Fri, 30 Nov 2001 20:15, Vincent Massol wrote:
> This is used in a generic method that is called to automatically log
> entries and exits of methods, so it is executed every time there is a log
> to be made for an entry/exit. It is thus called very often.

ouch. Question - why don't you cache it ?

> I'd like to know if it has any performance issue. More specifically, I'd
> like to know if the final keyword helps for performance (as it does for
> final methods which are inlined) 

a little bit.

> I guess that even with the final
> keyword, there is always a new object instanciated in memory ...

yep. However depending on what JVM you are using it will come almost for 
free. In JDK1.4 there would be virtually no cost (because it is a small 
shortlived lightweight object), in JDK1.2 there is still a bit of a cost ;(

JDK1.3 is inbetween though I believe there is a command line switch to enable 
a different GCs and I believe this may help a little.

> So, I also guess that simply writing :
>
> Category category = Category.getInstance(targetName);
>
> would be more performant ?

maybe or maybe not. There could be zero difference depending on the JVMs GC 
and quality of jit compiler. Best idea is to take a representative method. 
Run it for 10 minutes (to "warm" up the hotspot if thats what you are using 
it for) then test how many runs can occur in a minute (use 
NoopAppenders to ignore IO differences). Repeat this for each 
different version and you should an an okay representation of difference in 
performance.

However I think you will find that it is directly related to type of Appender 
rather than the object wrapper.

-- 
Cheers,

Pete

--------------------------------
 These aren't the droids you're 
 looking for. Move along. 
--------------------------------


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>

Re: Loggers, final classes and performance

[Vincent Massol <vm...@octo.com>]

Ok, Thanks Leo.

I agree with you but the operations are additive (and not in parallel), so
I'm trying to squeeze the maximum of log information for the same price :).
Logging will stay enabled during production but we want to be able to turn
it off/on/change level dynamically, so the if (LOGGING) would not work. The
"new" will instanciate about 10K logger objects per second and I was just
wondering if it would make any difference (especially by triggering the gc
more frequently maybe).

But I agree this is probably negligible compared to other stuff.
Thanks
-Vincent


----- Original Message -----
From: "Leo Sutic" <le...@inspireinfrastructure.com>
To: "Avalon Developers List" <av...@jakarta.apache.org>; "Vincent
Massol" <vm...@octo.com>
Sent: Friday, November 30, 2001 1:12 PM
Subject: RE: Loggers, final classes and performance


> Vincent,
>
> I think the overhead of one object creation is negligible in this case. If
> you log something, then you have:
>
>  1) Object creation.
>  2) Function call to logger.
>  3) IO operation (write the log entry).
>
> Of these three, number 3 is the overwhelmingly slowest operation.
>
> If you have your log statements inside your innermost loops, the consider
> wrapping them in a:
>
> if (LOGGING) {
> ...
> }
>
> where LOGGING is a static final boolean variable. I read somewhere that
this
> will have the same effect as conditional compilation.
>
> If you do not have log statements inside your innermost loops, the loop
> itself probably overwhelms the performance penalty of a maybe-log. Then
> again, if you do log something, and it involves disk access, it will
> overwhelm most non-I/O bound operations.
>
> In short - if you get performance problems, your problem is not the extra
> wrapper object, it is the fact that you are logging too much.
>
> /LS
>
> > -----Original Message-----
> > From: Vincent Massol [mailto:vmassol@octo.com]
> > Sent: den 30 november 2001 10:16
> > To: avalon-dev@jakarta.apache.org
> > Subject: Loggers, final classes and performance
> >
> >
> > Hi,
> >
> > I need your expert advice here. The Log4JLogger class is declared
> > as a final
> > class. In my code, I use :
> >
> > Logger logger = new Log4JLogger(
> >     Category.getInstance(targetName));
> >
> > This is used in a generic method that is called to automatically
> > log entries
> > and exits of methods, so it is executed every time there is a log
> > to be made
> > for an entry/exit. It is thus called very often.
> >
> > I'd like to know if it has any performance issue. More specifically, I'd
> > like to know if the final keyword helps for performance (as it does for
> > final methods which are inlined) : I guess that even with the
> > final keyword,
> > there is always a new object instanciated in memory ...
> >
> > So, I also guess that simply writing :
> >
> > Category category = Category.getInstance(targetName);
> >
> > would be more performant ?
> >
> > Another solution would be to have a hashmap of all loggers and
> > check in the
> > hashmap whether the logger for a given targetName already exist
> > and then use
> > that logger if it does. However, the additional work (putting the
> > instances
> > in the hash, possibly with synchronisation (argh!), then doing an "if"
and
> > then fetching the logger from the hash) might overall be more costly
that
> > instanciating a new object.
> >
> > What do you think ? Any idea ?
> > Thanks
> > -Vincent
> >
> >
> >
> > --
> > To unsubscribe, e-mail:
> <ma...@jakarta.apache.org>
> For additional commands, e-mail:
<ma...@jakarta.apache.org>
>
>
>


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>

RE: Loggers, final classes and performance

[Leo Sutic <le...@inspireinfrastructure.com>]

Vincent,

I think the overhead of one object creation is negligible in this case. If
you log something, then you have:

 1) Object creation.
 2) Function call to logger.
 3) IO operation (write the log entry).

Of these three, number 3 is the overwhelmingly slowest operation.

If you have your log statements inside your innermost loops, the consider
wrapping them in a:

if (LOGGING) {
	...
}

where LOGGING is a static final boolean variable. I read somewhere that this
will have the same effect as conditional compilation.

If you do not have log statements inside your innermost loops, the loop
itself probably overwhelms the performance penalty of a maybe-log. Then
again, if you do log something, and it involves disk access, it will
overwhelm most non-I/O bound operations.

In short - if you get performance problems, your problem is not the extra
wrapper object, it is the fact that you are logging too much.

/LS

> -----Original Message-----
> From: Vincent Massol [mailto:vmassol@octo.com]
> Sent: den 30 november 2001 10:16
> To: avalon-dev@jakarta.apache.org
> Subject: Loggers, final classes and performance
>
>
> Hi,
>
> I need your expert advice here. The Log4JLogger class is declared
> as a final
> class. In my code, I use :
>
> Logger logger = new Log4JLogger(
>     Category.getInstance(targetName));
>
> This is used in a generic method that is called to automatically
> log entries
> and exits of methods, so it is executed every time there is a log
> to be made
> for an entry/exit. It is thus called very often.
>
> I'd like to know if it has any performance issue. More specifically, I'd
> like to know if the final keyword helps for performance (as it does for
> final methods which are inlined) : I guess that even with the
> final keyword,
> there is always a new object instanciated in memory ...
>
> So, I also guess that simply writing :
>
> Category category = Category.getInstance(targetName);
>
> would be more performant ?
>
> Another solution would be to have a hashmap of all loggers and
> check in the
> hashmap whether the logger for a given targetName already exist
> and then use
> that logger if it does. However, the additional work (putting the
> instances
> in the hash, possibly with synchronisation (argh!), then doing an "if" and
> then fetching the logger from the hash) might overall be more costly that
> instanciating a new object.
>
> What do you think ? Any idea ?
> Thanks
> -Vincent
>
>
>
> --
> To unsubscribe, e-mail:
<ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>



--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>