dev@glassfish.java.net

Re: Please consider avoiding concatenated log messages

From: Vince Kraemer <vince.kraemer_at_oracle.com>
Date: Tue, 26 Jul 2011 16:09:11 -0700

Byron Nevins wrote:
> What slows it down 7 fold? Is it
>
> Logger.fine(something) versus Logger.log(Level.FINE, something)

These two statements are really fast when the Level is INFO... the
.log(Level,String) looks to be about 1 milli slower (over 1000000)
invocations....

>
> Or is it concatenation versus having logger fill-in the {0}

This is the part that gets you...

In the .fine("foo" + detail) case, there is a toString() and a
concatenation happening BEFORE the Level is checked.

In the .log(Level,String,Obj) case, the toString() of the Object and the
formating of the message happen IF the Level check passes, but both are
skipped otherwise.

I have also noticed some cases of things like this
.fine(strings.get("message.key")) which seems like it will be slow....
but I haven't come up with a good fix for that kind of case.

vbk



>
> ????????????
>
>
>
> On 7/26/2011 11:02 AM, Bobby Bissett wrote:
>> On 7/26/11 12:52 PM, Vince Kraemer wrote:
>>> Hi all,
>>>
>>> I noticed some lines (about 1350) like this
>>>
>>> logger.fine("some message: " + varForDetail);
>>>
>>> in our code.
>>>
>>> This is 'equal to'
>>>
>>> logger.log(Level.FINE, "some message: {0}", varForDetail);
>>>
>>> but it seems like this second form is about 7 times faster to
>>> execute, if the logging level is Level.INFO....