<div class="gmail_quote"><div>Thanks for a quick reply.<br><br>With that performance figures while using logback, I agree this is not an improvement. <br><br>The other best we can do is to have a convenience method in logback api which accepts format, and args directly; in addition to the current api which just accepts a msgStr.<br>
<br>Maybe this clutters api, with more methods. Considering improved performance with logback, I think what we have is fine.<br><br>Regards,<br>Srini<br></div><blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">
<br>
<br>
Message: 1<br>
Date: Thu, 23 Oct 2008 19:20:52 +0200<br>
From: Ceki Gulcu <listid@qos.ch><br>
Subject: Re: [slf4j-user] Double Checking log level when logging with<br>
log4j<br>
To: User list for the slf4j project <<a href="mailto:user@slf4j.org">user@slf4j.org</a>><br>
Message-ID: <4900B274.9020309@qos.ch><br>
Content-Type: text/plain; charset=UTF-8; format=flowed<br>
<br>
Hello Srinivasan,<br>
<br>
The logger.isEnabledFor(...) operation takes about 25 nanoseconds with log4j and<br>
about 10 nanoseconds with logback. new InterpolatedMessage probably takes longer<br>
than that..<br>
<br>
Srinivasan Raguraman wrote:<br>
> When we are using log4j as underlying logger, sl4j actually does double<br>
> checking of 'isErrorEnabled()' for every Log, if that LEVEL is enabled.<br>
><br>
><br>
><br>
> public void error(String format, Object arg) {<br>
><br>
> if (logger.isEnabledFor(Level.ERROR)) {<br>
><br>
> String msgStr = MessageFormatter.format(format, arg);<br>
><br>
> logger.log(FQCN, Level.ERROR, msgStr, null);<br>
><br>
> }<br>
><br>
> }<br>
><br>
><br>
><br>
> This is because, once we pass the message to log4j<br>
><br>
><br>
><br>
> logger.log(FQCN, Level.ERROR, msgStr, null);<br>
><br>
><br>
><br>
><br>
><br>
> log4j library again does the check isErrorEnabled() before the actual<br>
> logging. This code is the same as the isErrorEnabled check.<br>
><br>
><br>
><br>
> *public*<br>
><br>
> *void* log(String callerFQCN, Priority level, Object message,<br>
> Throwable t) {<br>
><br>
> *if*(repository.isDisabled(level.level)) {<br>
><br>
> *return*;<br>
><br>
> }<br>
><br>
> *if*(level.isGreaterOrEqual(*this*.getEffectiveLevel())) {<br>
><br>
> forcedLog(callerFQCN, level, message, t);<br>
><br>
> }<br>
><br>
> }<br>
><br>
><br>
><br>
> To avoid this double checking why don't we wrap the format, arguments<br>
> inside an Object, and use log4j renderer for that object to generate the<br>
> final message? Or even override toString() method of that object to<br>
> return the formatted message.<br>
><br>
><br>
><br>
><br>
><br>
> Instead of this:<br>
><br>
><br>
><br>
> logger.log(FQCN, Level.ERROR, msgStr, null);<br>
><br>
><br>
><br>
> It could be something like:<br>
><br>
><br>
><br>
> public void error(String format, Object arg) {<br>
><br>
> logger.log(FQCN, Level.ERROR, new InterpolatedMessage(formate, arg), null);<br>
><br>
> }<br>
><br>
><br>
><br>
><br>
><br>
> Where<br>
><br>
><br>
><br>
> public final class InterpolatedMessage {<br>
><br>
><br>
><br>
> private final String format;<br>
><br>
> private final Object arg;<br>
><br>
><br>
><br>
> public InterpolatedMessage(final String format, final Object<br>
> arg) {<br>
><br>
> this.format = format;<br>
><br>
> this.arg = arg;<br>
><br>
> }<br>
><br>
><br>
><br>
> @Override<br>
><br>
> public String toString() {<br>
><br>
> return MessageFormatter.format(this.format,<br>
> this.arg);<br>
><br>
> }<br>
><br>
><br>
><br>
> }<br>
><br>
><br>
><br>
><br>
><br>
> As you see, this will<br>
><br>
><br>
><br>
> * Delay the message construction unless it really going to be used.<br>
> * Avoid double checking with if LevelEnabled, when that level is<br>
> actually enabled<br>
><br>
><br>
><br>
> The negatives are<br>
><br>
><br>
><br>
> * Creation of InterpolatedMessage Object for every log statement ?<br>
> since the object is just going to hold the reference of the format<br>
> and args, this may not be expensive?<br>
> o as it avoids construction of log message<br>
> * Using toString() method of interpolated message is a trick! -<br>
> Yes, for that we can otherwise add log4j renderer for objects of<br>
> InterpolatedMessage type.<br>
><br>
><br>
><br>
><br>
><br>
> I just gave my thoughts here; let me know what you guys think. I could<br>
> follow up or help to verify if this will really gives us performance<br>
> advantage.<br>
><br>
><br>
><br>
> Regards,<br>
><br>
> Srini<br>
><br>
><br>
> ------------------------------------------------------------------------<br>
><br>
> _______________________________________________<br>
> user mailing list<br>
> <a href="mailto:user@slf4j.org">user@slf4j.org</a><br>
> <a href="http://www.slf4j.org/mailman/listinfo/user" target="_blank">http://www.slf4j.org/mailman/listinfo/user</a><br>
<br>
--<br>
Ceki G?lc?<br>
Logback: The reliable, generic, fast and flexible logging framework for Java.<br>
<a href="http://logback.qos.ch" target="_blank">http://logback.qos.ch</a><br>
<br>
<br>
------------------------------<br>
<br>
_______________________________________________<br>
user mailing list<br>
<a href="mailto:user@slf4j.org">user@slf4j.org</a><br>
<a href="http://www.slf4j.org/mailman/listinfo/user" target="_blank">http://www.slf4j.org/mailman/listinfo/user</a><br>
<br>
End of user Digest, Vol 26, Issue 12<br>
************************************<br>
</blockquote></div><br><br clear="all"><br>-- <br>Regards,<br>Srini<br>