Hello Mandeep,
Thanks for pointing the slide, I'll check it out. Anyway, after the last
optimizations, our parametrized calls are now even faster than log4j's
isDebugEnabled() method... :)
Logback does not fit into commons logging. However, SLF4J provides a jar that
redirects all calls to JCL to SLF4J. If you are using SLF4J with logback, every call
made to the commons logging framework will be directed to logback.
You might be interested in reading the "Gradual migration to SLF4J from Jakarta
Commons Logging (JCL)" part in the SLF4J manual[1]. Calls to log4j can be directed to
logback by using the log4j-bridge module, that is shipped with logback. You can read
about it here[2].
Hope this helps,
Sébastien
[1]http://slf4j.org/manual.html
[2]http://logback.qos.ch/bridge.html
Mandeep Singh wrote:
Hello Sebastian,
Thanks a lot for ur replies and all the efforts that u have put in into
this great product. I will surely test this new code. In ur previous
reply u had asked me the source of my assumption that the parameterized
call is faster then "isDebugEnabled". Well I misinterpreted the "10
reasons to use logback" slideshow that is available on the logback site
.. I am pasting the contents of the slide (Slide number 21) that
confused me, maybe u can consider rewording it -
Integer entry = new Interger(50);
logger.debug("The entry is "+entry+".");
can be optimized as:
if(logger.isDebugEnabled()) {
logger.debug("The entry is "+entry+".");
}
or better yet:
logger.debug("The entry is *{}*.", entry);
so u see that the second and third point are not actually related ...:)
Also I have another small query , my project uses a mixture of commons
logging and log4j, also some of the thirdparty libraries that we use,
are using commons. Where does logback fit in commons ? Can u point me a
doc which i can refer for the same.
once again thanks for all ur help.
regards
Mandeep
----- Original Message ----
From: Sebastien Pennec <[EMAIL PROTECTED]>
To: logback users list <[email protected]>
Sent: Tuesday, March 13, 2007 11:41:16 AM
Subject: Re: [logback-user] logback performance clarification
Hello Mandeep,
After some research and performance optimizations, here are the results
I've
obtained. Times are shown in nanoseconds per requests, and are an
average time after
1'000'000 requests.
Log4j direct debug call: 442
Log4j tested (isDebugEnabled) debug call: 19
Logback direct debug call: 435
Logback tested (isDebugEnabled) debug call: 10
Logback parametrized debug call: 15
They are rather different than what I had witnessed previously.
First of all, the procedure is closer to a real life example. The
PerformanceComparator class is nested into a 4-level deep package, and
not in the top
package. Then, only the root loggers have a level set explicitly. That
means that
both logging frameworks have to include level inheritance when deciding
to log or not.
This show how logback performs faster than log4j when relying on level
inheritance.
The tested call (using isDebugEnabled()) in logback is almost 2 times
faster than its
log4j counterpart.
Then, we've made a few optimizations in logback's Logger class. There
are now less
method calls, and smarter if statements when recieving the TurboFilter's
reply. This
has made the parametrized call much faster. This form is now faster than
log4j's
isDebugEnabled() form.
Since TurboFilters are a big feature of logback, I should mention that
they are
called when using the direct call or the parametrized call, but also
when calling
isDebugEnabled(). For example, you might want to set your levels to INFO
or WARN in
production, and add a TurboFilter that sets the level to DEBUG for a
certain user.
Having the username in the MDC, you can easily add a TurboFilter that
will always
accept the log requests when they are issued by this user's actions,
although the
logger would not accept such requests coming from any other user.
The isDebugEnabled will then return false every time, except when the
current user is
logged with the username to allow debug level.
I've attached the class I used to get these results at the end of this
email. You
might want to try it on your environment and see if the performance
satisfy your
needs. You will need to checkout logback from its source repository[1][2]
Cheers,
Sébastien
[1]http://logback.qos.ch/repos.html
[2]http://logback.qos.ch/manual/introduction.html#BuildingLogback
package perfTest.ch.qos.logback;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class PerformanceComparator {
static Logger logbacklogger = LoggerFactory
.getLogger(PerformanceComparator.class);
static org.apache.log4j.Logger log4jlogger = org.apache.log4j.Logger
.getLogger(PerformanceComparator.class);
// How many times should we try to log:
static int loop = 1000000;
public static void main(String[] args) throws InterruptedException {
initConfig();
// Let's run once for Just In Time compiler
log4jDirectDebugCall();
log4jTestedDebugCall();
logbackDirectDebugCall();
logbackTestedDebugCall();
logbackParametrizedDebugCall();
// let's run the tests and display the results:
long result1 = log4jDirectDebugCall();
long result2 = log4jTestedDebugCall();
long result3 = logbackDirectDebugCall();
long result4 = logbackTestedDebugCall();
long result5 = logbackParametrizedDebugCall();
System.out.println("###############################################");
System.out.println("Log4j direct debug call: " + result1);
System.out.println("Log4j tested (isDebugEnabled) debug call: " +
result2);
System.out.println("Logback direct debug call: " + result3);
System.out
.println("Logback tested (isDebugEnabled) debug call: " + result4);
System.out.println("Logback parametrized debug call: " + result5);
System.out.println("###############################################");
}
private static long log4jDirectDebugCall() {
Integer j = new Integer(2);
long start = System.nanoTime();
for (int i = 0; i < loop; i++) {
log4jlogger.debug("SEE IF THIS IS LOGGED " + j + ".");
}
return (System.nanoTime() - start) / loop;
}
private static long log4jTestedDebugCall() {
Integer j = new Integer(2);
long start = System.nanoTime();
for (int i = 0; i < loop; i++) {
if (log4jlogger.isDebugEnabled()) {
log4jlogger.debug("SEE IF THIS IS LOGGED " + j + ".");
}
}
return (System.nanoTime() - start) / loop;
}
private static long logbackDirectDebugCall() {
Integer j = new Integer(2);
long start = System.nanoTime();
for (int i = 0; i < loop; i++) {
logbacklogger.debug("SEE IF THIS IS LOGGED " + j + ".");
}
return (System.nanoTime() - start) / loop;
}
private static long logbackTestedDebugCall() {
Integer j = new Integer(2);
long start = System.nanoTime();
for (int i = 0; i < loop; i++) {
if (logbacklogger.isDebugEnabled())
logbacklogger.debug("SEE IF THIS IS LOGGED " + j + ".");
}
return (System.nanoTime() - start) / loop;
}
private static long logbackParametrizedDebugCall() {
Integer j = new Integer(2);
long start = System.nanoTime();
for (int i = 0; i < loop; i++) {
logbacklogger.debug("SEE IF THIS IS LOGGED {}.", j);
}
return (System.nanoTime() - start) / loop;
}
private static void initConfig() {
org.apache.log4j.Logger log4jRoot =
org.apache.log4j.Logger.getRootLogger();
log4jRoot.setLevel(org.apache.log4j.Level.INFO);
ch.qos.logback.classic.Logger lbRoot =
(ch.qos.logback.classic.Logger) LoggerFactory
.getLogger("ROOT");
lbRoot.setLevel(ch.qos.logback.classic.Level.INFO);
// create the loggers
org.apache.log4j.Logger.getLogger("perfTest");
org.apache.log4j.Logger.getLogger("perfTest.ch");
org.apache.log4j.Logger.getLogger("perfTest.ch.qos");
org.apache.log4j.Logger.getLogger("perfTest.ch.qos.logback");
LoggerFactory.getLogger("perfTest");
LoggerFactory.getLogger("perfTest.ch");
LoggerFactory.getLogger("perfTest.ch.qos");
LoggerFactory.getLogger("perfTest.ch.qos.logback");
}
}
--
Sébastien Pennec
[EMAIL PROTECTED]
Logback: The reliable, generic, fast and flexible logging framework for
Java.
http://logback.qos.ch/
_______________________________________________
Logback-user mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-user
------------------------------------------------------------------------
Sucker-punch spam <
http://us.rd.yahoo.com/evt=49981/*http://advision.webevents.yahoo.com/mailbeta/features_spam.html>
with award-winning protection.
Try the free Yahoo! Mail Beta. <
http://us.rd.yahoo.com/evt=49981/*http://advision.webevents.yahoo.com/mailbeta/features_spam.html>
------------------------------------------------------------------------
_______________________________________________
Logback-user mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-user
--
Sébastien Pennec
[EMAIL PROTECTED]
Logback: The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch/
_______________________________________________
Logback-user mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-user
