June 2009 - logback-dev - mailman3.qos.ch

[JIRA] Updated: (LBCLASSIC-36) Synchronization of SimpleDateFormat object in DateConverter
by Ralph Goers (JIRA) 14 Jun '09

14 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-36?page=com.atlassian.jira.plugin.syste… ] Ralph Goers updated LBCLASSIC-36: --------------------------------- Attachment: dateformattest.zip Test to compare various ways of using SimpleDateFormat vs Joda Time. > Synchronization of SimpleDateFormat object in DateConverter > ----------------------------------------------------------- > > Key: LBCLASSIC-36 > URL: http://jira.qos.ch/browse/LBCLASSIC-36 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Anders Hammar > Assignee: Ceki Gulcu > Attachments: DateConverter_patch.java, dateformattest.zip > > > According to the API documentation of SimpleDateFormat, date formats are not synchronized and it is recommended to create separate format instances for each thread. > However, a possibly simpler (mer efficient) solution would be to synchronize on the SimpleDateFormat object in the convert() method to prevent two threads to access it concurrently. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

Throughput of fair locks
by Ceki Gulcu 13 Jun '09

13 Jun '09

Hello all, I added a new application measuring the compared throughtput of the synchronized primitive versus fair and unfair locks. Here are the results. java.runtime.version = 1.6.0_11-b03 java.vendor = Sun Microsystems Inc. java.version = 1.6.0_11 os.name = Linux os.version = 2.6.25-gentoo-r6 Sync: 139698775, or 35 nanos per cycle Unfair: 87028802, or 57 nanos per cycle Fair: 4106449, or 1217 nanos per cycle java.runtime.version = jvmxa6460-20081105_25433 java.vendor = IBM Corporation java.version = 1.6.0 os.name = Linux os.version = 2.6.25-gentoo-r6 Sync: 356946629, or 14 nanos per cycle Unfair: 91892449, or 54 nanos per cycle Fair: 7380308, or 677 nanos per cycle As you can see there is a substantial difference in throughput. The ration is about 40. Cheers, -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

1 0

svn commit: r2289 - logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue
by noreply.ceki＠qos.ch 13 Jun '09

13 Jun '09

Author: ceki Date: Sat Jun 13 23:42:34 2009 New Revision: 2289 Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockingInJava.java (contents, props changed) Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockingInJava.java Log: - Measure performance when no locking is present. - We don't need to interrupt in LockingInJava Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockingInJava.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockingInJava.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockingInJava.java Sat Jun 13 23:42:34 2009 @@ -11,11 +11,12 @@ static int THREAD_COUNT = 5; static Object LOCK = new Object(); - static Runnable[] RUNNABLE_ARRAY = new Runnable[THREAD_COUNT]; + static LockingInJava[] RUNNABLE_ARRAY = new LockingInJava[THREAD_COUNT]; static Thread[] THREAD_ARRAY = new Thread[THREAD_COUNT]; private int counter = 0; - + private boolean done = false; + public static void main(String args[]) throws InterruptedException { printEnvironmentInfo(); execute(); @@ -47,9 +48,9 @@ Thread.sleep(10000); for (int i = THREAD_COUNT - 1; i <= 0; i--) { - THREAD_ARRAY[i].interrupt(); + RUNNABLE_ARRAY[i].done = true; } - Thread.sleep(100); // wait a moment for termination, to lazy for join ;) + } public static void printResults() { @@ -65,7 +66,9 @@ try { Thread.sleep(10); } catch (InterruptedException ex) { - break; + } + if(done) { + return; } } } Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockingInJava.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockingInJava.java Sat Jun 13 23:42:34 2009 @@ -0,0 +1,74 @@ +package ch.qos.logback.core.issue; + +/** + * Measure throughput without any locking policy + * + * @author Joern Huxhorn + * @author Ceki Gulcu + */ +public class NoLockingInJava implements Runnable { + + static int THREAD_COUNT = 5; + static Object LOCK = new Object(); + static NoLockingInJava[] RUNNABLE_ARRAY = new NoLockingInJava[THREAD_COUNT]; + static Thread[] THREAD_ARRAY = new Thread[THREAD_COUNT]; + + private int counter = 0; + private boolean done = false; + + public static void main(String args[]) throws InterruptedException { + printEnvironmentInfo(); + execute(); + printResults(); + } + + public static void printEnvironmentInfo() { + System.out.println("java.runtime.version = " + + System.getProperty("java.runtime.version")); + System.out.println("java.vendor = " + + System.getProperty("java.vendor")); + System.out.println("java.version = " + + System.getProperty("java.version")); + System.out.println("os.name = " + + System.getProperty("os.name")); + System.out.println("os.version = " + + System.getProperty("os.version")); + } + + public static void execute() throws InterruptedException { + for (int i = 0; i < THREAD_COUNT; i++) { + RUNNABLE_ARRAY[i] = new NoLockingInJava(); + THREAD_ARRAY[i] = new Thread(RUNNABLE_ARRAY[i]); + } + for (Thread t : THREAD_ARRAY) { + t.start(); + } + // let the threads run for a while + Thread.sleep(10000); + + for (int i = THREAD_COUNT - 1; i <= 0; i--) { + RUNNABLE_ARRAY[i].done = true; + } + + } + + public static void printResults() { + for (int i = 0; i < RUNNABLE_ARRAY.length; i++) { + System.out.println("runnable[" + i + "]: " + RUNNABLE_ARRAY[i]); + } + } + + public void run() { + for (;;) { + counter++; + if (done) { + return; + } + } + } + + public String toString() { + return "counter=" + counter; + } + +}

1 0

svn commit: r2288 - logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue
by noreply.ceki＠qos.ch 13 Jun '09

13 Jun '09

Author: ceki Date: Sat Jun 13 23:31:29 2009 New Revision: 2288 Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java (contents, props changed) Log: Code comparing the throughput of fair lock and that of sync blocks Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java Sat Jun 13 23:31:29 2009 @@ -0,0 +1,141 @@ +package ch.qos.logback.core.issue; + +import java.util.concurrent.locks.Lock; +import java.util.concurrent.locks.ReentrantLock; + +/** + * Short sample code testing the throughput of a fair lock. + * + * @author Joern Huxhorn + * @author Ceki Gulcu + */ +public class LockThroughput implements Runnable { + + enum LockingModel { + SYNC, FAIR, UNFAIR; + } + + static int THREAD_COUNT = 2; + static long OVERALL_DURATION_IN_MILLIS = 5000; + static LockThroughput[] RUNNABLE_ARRAY = new LockThroughput[THREAD_COUNT]; + static Thread[] THREAD_ARRAY = new Thread[THREAD_COUNT]; + + static Object LOCK = new Object(); + static Lock FAIR_LOCK = new ReentrantLock(true); + static Lock UNFAIR_LOCK = new ReentrantLock(false); + + static private int COUNTER = 0; + + LockingModel model; + boolean done = false; + + public static void main(String args[]) throws InterruptedException { + printEnvironmentInfo(); + execute(LockingModel.SYNC); + execute(LockingModel.UNFAIR); + execute(LockingModel.FAIR); + + COUNTER = 0; + execute(LockingModel.SYNC); + cleanUpAndPrintResults("Sync: "); + execute(LockingModel.UNFAIR); + cleanUpAndPrintResults("Unfair: "); + execute(LockingModel.FAIR); + cleanUpAndPrintResults("Fair: "); + + } + + public static void printEnvironmentInfo() { + System.out.println("java.runtime.version = " + + System.getProperty("java.runtime.version")); + System.out.println("java.vendor = " + + System.getProperty("java.vendor")); + System.out.println("java.version = " + + System.getProperty("java.version")); + System.out.println("os.name = " + + System.getProperty("os.name")); + System.out.println("os.version = " + + System.getProperty("os.version")); + } + + public static void execute(LockingModel model) throws InterruptedException { + for (int i = 0; i < THREAD_COUNT; i++) { + RUNNABLE_ARRAY[i] = new LockThroughput(model); + THREAD_ARRAY[i] = new Thread(RUNNABLE_ARRAY[i]); + } + for (Thread t : THREAD_ARRAY) { + t.start(); + } + // let the threads run for a while + Thread.sleep(OVERALL_DURATION_IN_MILLIS); + + for (int i = 0; i < THREAD_COUNT; i++) { + RUNNABLE_ARRAY[i].done = true; + } + } + + public static void cleanUpAndPrintResults(String model) throws InterruptedException { + for (int i = 0; i < THREAD_COUNT; i++) { + THREAD_ARRAY[i].join(); + } + System.out.println(model + COUNTER+", or "+ ((OVERALL_DURATION_IN_MILLIS*1000*1000L)/COUNTER) +" nanos per cycle"); + COUNTER = 0; + } + + LockThroughput(LockingModel model) { + this.model = model; + } + + + void fairLockRun() { + for (;;) { + FAIR_LOCK.lock(); + COUNTER++; + FAIR_LOCK.unlock(); + if (done) { + return; + } + } + } + + void unfairLockRun() { + for (;;) { + UNFAIR_LOCK.lock(); + COUNTER++; + UNFAIR_LOCK.unlock(); + if (done) { + return; + } + } + } + + void synchronizedRUn() { + for (;;) { + synchronized (LOCK) { + COUNTER++; + if (done) { + return; + } + } + } + } + + public void run() { + switch (model) { + case SYNC: + synchronizedRUn(); + break; + case FAIR: + fairLockRun(); + break; + case UNFAIR: + unfairLockRun(); + break; + } + } + + public String toString() { + return "counter=" + COUNTER; + } + +}

1 0

svn commit: r2287 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133
by noreply.ceki＠qos.ch 13 Jun '09

13 Jun '09

Author: ceki Date: Sat Jun 13 17:34:06 2009 New Revision: 2287 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java Log: LBCLASSIC-133 We don't need to unit test test. A standalone app, is just as good if not simpler to run. Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java Sat Jun 13 17:34:06 2009 @@ -2,28 +2,31 @@ import static org.junit.Assert.assertFalse; -import org.junit.Test; import org.slf4j.Logger; import org.slf4j.LoggerFactory; public class DeadlockTest { private static Logger s_logger = LoggerFactory.getLogger(DeadlockTest.class); - @Test - public void deadlockTest() throws Exception { + public static void main(String[] args) throws Exception { s_logger.debug("Starting test."); final Worker worker = new Worker(); final Thread workerThread = new Thread(new Runnable() { public void run() { - worker.work(); + while (true) { + worker.work(); + } } }); workerThread.setName("WorkerThread"); final Thread accessorThread = new Thread(new Runnable() { public void run() { - new Accessor().access(worker); + Accessor a = new Accessor(); + while (true) { + a.access(worker); + } } }); accessorThread.setName("AccessorThread"); @@ -31,7 +34,7 @@ workerThread.start(); accessorThread.start(); - workerThread.join(5 * 1000); + workerThread.join(50 * 1000); assertFalse("Worker thread seems locked.", workerThread.isAlive()); } }

1 0

svn commit: r2286 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133
by noreply.ceki＠qos.ch 13 Jun '09

13 Jun '09

Author: ceki Date: Sat Jun 13 17:16:07 2009 New Revision: 2286 Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Accessor.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Worker.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/logback-test.xml Log: files associated with LBCLASSIC-133 Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Accessor.java ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Accessor.java Sat Jun 13 17:16:07 2009 @@ -0,0 +1,23 @@ +package ch.qos.logback.classic.issue.lbclassic133; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class Accessor { + private static Logger s_logger = LoggerFactory.getLogger(Accessor.class); + + public void access(Worker worker) { + /** + * at some point, for any reason, this method decides to log the status of + * the worker object. + */ + s_logger.debug("Current worker status is: {}.", worker); + /** + * the following line would not cause the deadlock, because the thread never + * tries to acquire a lock on worker while already having a lock on the + * logger. + */ + //s_logger.debug("Current worker status (not deadlocking) is: {}.", worker + // .toString()); + } +} Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java Sat Jun 13 17:16:07 2009 @@ -0,0 +1,37 @@ +package ch.qos.logback.classic.issue.lbclassic133; + +import static org.junit.Assert.assertFalse; + +import org.junit.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class DeadlockTest { + private static Logger s_logger = LoggerFactory.getLogger(DeadlockTest.class); + + @Test + public void deadlockTest() throws Exception { + s_logger.debug("Starting test."); + + final Worker worker = new Worker(); + final Thread workerThread = new Thread(new Runnable() { + public void run() { + worker.work(); + } + }); + workerThread.setName("WorkerThread"); + + final Thread accessorThread = new Thread(new Runnable() { + public void run() { + new Accessor().access(worker); + } + }); + accessorThread.setName("AccessorThread"); + + workerThread.start(); + accessorThread.start(); + + workerThread.join(5 * 1000); + assertFalse("Worker thread seems locked.", workerThread.isAlive()); + } +} Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Worker.java ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Worker.java Sat Jun 13 17:16:07 2009 @@ -0,0 +1,40 @@ +package ch.qos.logback.classic.issue.lbclassic133; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class Worker { + private static Logger s_logger = LoggerFactory.getLogger(Worker.class); + + private final Object m_lock = new Object(); + + public void work() { + // Locks the object to do some work changing internal status. + synchronized (m_lock) { + // Does some work... + try { + Thread.sleep(1 * 1000); + } catch (InterruptedException exc) { + // + } + // Then calls logger, while still holding the lock. + s_logger.debug("Did some work, result is: {}."/* ,... */); + } + } + + public String getStatus() { + // Locks the object to make sure the status snapshot is coherent. (Will + // deadlock.) + synchronized (m_lock) { + // Packs some status information, e.g. in a StringBuffer. + final StringBuffer buf = new StringBuffer("STATUS"); + // Returns the string. + return buf.toString(); + } + } + + @Override + public String toString() { + return getStatus(); + } +} \ No newline at end of file Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/logback-test.xml ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/logback-test.xml Sat Jun 13 17:16:07 2009 @@ -0,0 +1,16 @@ +<?xml version="1.0" encoding="UTF-8"?> +<configuration> + + <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> + <layout class="ch.qos.logback.classic.PatternLayout"> + <param name="Pattern" + value="%relative %level [%thread] %logger{25} %message %nopex\n" /> + </layout> + </appender> + + <root> + <level value="DEBUG" /> + <appender-ref ref="STDOUT" /> + </root> + +</configuration> \ No newline at end of file

1 0

[JIRA] Updated: (LBCLASSIC-45) Suggestion: Make LoggingEvent dumber, Logger more intelligent
by Ceki Gulcu (JIRA) 13 Jun '09

13 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-45?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu updated LBCLASSIC-45: -------------------------------- Comment: was deleted > Suggestion: Make LoggingEvent dumber, Logger more intelligent > ------------------------------------------------------------- > > Key: LBCLASSIC-45 > URL: http://jira.qos.ch/browse/LBCLASSIC-45 > Project: logback-classic > Issue Type: Improvement > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Joern Huxhorn > Assignee: Logback dev list > Priority: Minor > > This change would introduce incompatibilities with previous versions but would increase general logging performance and decrease size of serialized events. > After I have turned you off sufficiently ;), let me explain my idea: > At the moment, LoggingEvent is handling it's own initialization. It even contains measures against manipulation after initialization in that a call of a setter results in an IllegalStateException if the attribute has already been initialized before. > Instead, I'd suggest that LoggingEvent is changed into a dumb data container with getter and setters for all it's attributes. > If it's really necessary to have a semi-const LoggingEvent I'd suggest to define LoggingEvent as an interface containing only the getters of the attributes and an implementation LoggingEventImpl that implements LoggingEvent including getters and setters. > This communicates the *intent* that LoggingEvents aren't supposed to be modified but nothing more. It would still be possible to change e.g. the content of an array like argumentArray. Even if the getter would return a copy of the contained array, generating heat in the process, it would *still* be possible to brutally manipulate the LoggingEvent using java.lang.reflection setAccessible(true) so it's just not possible to guarantee constness. > Instead of having a pseudo-const LoggingEvent let's dump the constness altogether and make it a dumb data container that contains no logic at all. This would instead be moved to the Logger class. > I'd also suggest to remove formattedMessage and change the argumentArray to String[]. > This is possible because logback-classic/slf4j promises formatted message, not LoggingEvent. > It would increase performance because a Logger would simply create a LoggingEvent without performing a possibly unnecessary formatting of the message. Creation of LoggingEvents should be as fast and simple as possible, obviously. > The formatting of the message should/would instead be performed in the appender (or, more generally, user of the event) if required. > A serializing appender, an xml appender (e.g. using java.beans.XMLEncoder) or a socket appender would *not* require a formatted message, executing significantly faster than before. > The argumentArray should be String[] to securely prevent java.io.NotSerializableException in the serializer and . java.lang.ClassNotFoundException in the deserializer. > LoggerRemoteView and LoggerContextRemoteView should be changed the same way as LoggingEvent, i.e. just data container, logic moved to Logger, for similar reasons. > I have to admit, though, that I currently don't understand the reason the LoggingEvent needs to know about LoggerContext beside resolving of the Logger name. I couldn't find code that uses LoggerContextRemoteView.getPropertyMap(), beside loading and saving it. > So I think it may be possible that LoggerRemoteView isn't really necessary and could be removed from LoggingEvent... remembering the Logger name instead. > fqnOfLoggerClass could be omitted because the CallerData would be created in the Logger where fqnOfLoggerClass is known. > And last but not least I'd also change Level into an java.lang.Enum. > I don't expect that all this will be done but I wanted to suggest it nevertheless because it would both increase performance and produce cleaner code. > Breaking compatibility would IMHO be worth it - after all, logback isn't 1.0, yet ;) > If you are interested I'd volunteer to implement those changes, after signing http://logback.qos.ch/cla.txt of course. > Keywords: > Inversion of Control (IoC), separation of concerns, KISS principle > Related bugs: > http://bugzilla.qos.ch/show_bug.cgi?id=100 > http://bugzilla.qos.ch/show_bug.cgi?id=118 > http://bugzilla.slf4j.org/show_bug.cgi?id=70 -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

[JIRA] Commented: (LBCLASSIC-45) Suggestion: Make LoggingEvent dumber, Logger more intelligent
by Ceki Gulcu (JIRA) 13 Jun '09

13 Jun '09

[ http://jira.qos.ch/browse/LBCLASSIC-45?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBCLASSIC-45: ------------------------------------- For the record, Thread "32900144@qtp0-0 - /cbs2/v1.0/ws/cbs2.wsdl" invokes o.m.jetty.servlet.ServletHandler.handle(ServletHandler.java:414) as a consequence, a few lines down the stack trace o.m.log.Slf4jLog.warn(Slf4jLog.java:128) is invoked and as a consequence, a few lines further c.q.l.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:60) is invoked. This latest call causes the thread to obtain a lock on "<0x7395a770> (a ch.qos.logback.core.ConsoleAppender)" During the logging process, PackagingDataCalculator.calculate is invoked, this causes the thread to invoke o.m.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:341) which attempts to obtain a lock on "<0x7391a760> (o.m.jetty.webapp.WebAppClassLoader)" which is already in possession of thread "15510444@qtp0-2" discussed below Thread "15510444@qtp0-2 - /cbs2/v1.0/ws/cbs2.wsdl" invokes org.mortbay.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:341) which obtains a lock on <0x7391a760> (a o.m.jetty.webapp.WebAppClassLoader) as a consequence, a few lines further o.m.log.Slf4jLog.debug(Slf4jLog.java:73) is invoked as a result, c.q.l.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:60) is invoked, this latest call attempts to lock <0x7395a770> (a c.q.l.core.ConsoleAppender) which is already in possession of thread "32900144@qtp0-0" as discussed above. The bug is an illustration of deadlocks occurring when a logback component, during the process of logging, invokes a service which does logging itself. There are two cheap and immediate ways to get rid of this *particular* bug. 1) reduce logging verbosity for the "org.mortbay.log" logger, which is the sole logger used by Jetty. This can be done by setting the level of "org.mortbay.log" logger to any level above or equal to INFO, that is INFO, WARN and ERROR. 2) disable the addition of packaging information in stack traces output by ConsoleAppender. This can be accomplished by adding "%ex" to the end of conversion pattern. For example, if the configuration snippet for ConsoleAppender is <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%-5r [%thread] %level - %msg%n</Pattern> </layout> </appender> then, change it to: <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout">  <Pattern>%-5r [%thread] %level - %msg%n%ex</Pattern> </layout> </appender> Of course, while these two solutions are cheap and yield immediate results, they are intellectually unsatisfactory. Reducing the locking granularity in AppenderBase would most probably get rid of the problem. Strictly speaking, as far as FileAppender and co. are concerned, the lock needs to be active only while writing to the file. In a similar fashion, the scope of lock could be reduced in many other appenders, with DBAppender as one notable exception. > Suggestion: Make LoggingEvent dumber, Logger more intelligent > ------------------------------------------------------------- > > Key: LBCLASSIC-45 > URL: http://jira.qos.ch/browse/LBCLASSIC-45 > Project: logback-classic > Issue Type: Improvement > Components: Other > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Joern Huxhorn > Assignee: Logback dev list > Priority: Minor > > This change would introduce incompatibilities with previous versions but would increase general logging performance and decrease size of serialized events. > After I have turned you off sufficiently ;), let me explain my idea: > At the moment, LoggingEvent is handling it's own initialization. It even contains measures against manipulation after initialization in that a call of a setter results in an IllegalStateException if the attribute has already been initialized before. > Instead, I'd suggest that LoggingEvent is changed into a dumb data container with getter and setters for all it's attributes. > If it's really necessary to have a semi-const LoggingEvent I'd suggest to define LoggingEvent as an interface containing only the getters of the attributes and an implementation LoggingEventImpl that implements LoggingEvent including getters and setters. > This communicates the *intent* that LoggingEvents aren't supposed to be modified but nothing more. It would still be possible to change e.g. the content of an array like argumentArray. Even if the getter would return a copy of the contained array, generating heat in the process, it would *still* be possible to brutally manipulate the LoggingEvent using java.lang.reflection setAccessible(true) so it's just not possible to guarantee constness. > Instead of having a pseudo-const LoggingEvent let's dump the constness altogether and make it a dumb data container that contains no logic at all. This would instead be moved to the Logger class. > I'd also suggest to remove formattedMessage and change the argumentArray to String[]. > This is possible because logback-classic/slf4j promises formatted message, not LoggingEvent. > It would increase performance because a Logger would simply create a LoggingEvent without performing a possibly unnecessary formatting of the message. Creation of LoggingEvents should be as fast and simple as possible, obviously. > The formatting of the message should/would instead be performed in the appender (or, more generally, user of the event) if required. > A serializing appender, an xml appender (e.g. using java.beans.XMLEncoder) or a socket appender would *not* require a formatted message, executing significantly faster than before. > The argumentArray should be String[] to securely prevent java.io.NotSerializableException in the serializer and . java.lang.ClassNotFoundException in the deserializer. > LoggerRemoteView and LoggerContextRemoteView should be changed the same way as LoggingEvent, i.e. just data container, logic moved to Logger, for similar reasons. > I have to admit, though, that I currently don't understand the reason the LoggingEvent needs to know about LoggerContext beside resolving of the Logger name. I couldn't find code that uses LoggerContextRemoteView.getPropertyMap(), beside loading and saving it. > So I think it may be possible that LoggerRemoteView isn't really necessary and could be removed from LoggingEvent... remembering the Logger name instead. > fqnOfLoggerClass could be omitted because the CallerData would be created in the Logger where fqnOfLoggerClass is known. > And last but not least I'd also change Level into an java.lang.Enum. > I don't expect that all this will be done but I wanted to suggest it nevertheless because it would both increase performance and produce cleaner code. > Breaking compatibility would IMHO be worth it - after all, logback isn't 1.0, yet ;) > If you are interested I'd volunteer to implement those changes, after signing http://logback.qos.ch/cla.txt of course. > Keywords: > Inversion of Control (IoC), separation of concerns, KISS principle > Related bugs: > http://bugzilla.qos.ch/show_bug.cgi?id=100 > http://bugzilla.qos.ch/show_bug.cgi?id=118 > http://bugzilla.slf4j.org/show_bug.cgi?id=70 -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

svn commit: r2285 - in logback/trunk: logback-classic/src/main/java/ch/qos/logback/classic/spi logback-site/src/site/pages logback-site/src/site/pages/manual
by noreply.ceki＠qos.ch 12 Jun '09

12 Jun '09

Author: ceki Date: Fri Jun 12 23:00:55 2009 New Revision: 2285 Added: logback/trunk/logback-site/src/site/pages/deadlock.html Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ILoggingEvent.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java logback/trunk/logback-site/src/site/pages/manual/appenders.html logback/trunk/logback-site/src/site/pages/manual/architecture.html logback/trunk/logback-site/src/site/pages/manual/filters.html logback/trunk/logback-site/src/site/pages/manual/layouts.html logback/trunk/logback-site/src/site/pages/manual/mdc.html logback/trunk/logback-site/src/site/pages/manual/migrationFromLog4j.html Log: - updating documentation to refer to ILoggingEvent instead of LoggingEvent where appropriate Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ILoggingEvent.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ILoggingEvent.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/ILoggingEvent.java Fri Jun 12 23:00:55 2009 @@ -7,7 +7,8 @@ import ch.qos.logback.classic.Level; /** - * The core interface in logback-classic. + * The central interface in logback-classic. In a nutshell, logback-classic is + * nothing more than a processing chain built around this interface. * * @author Ceki Gülcü * @since 0.9.16 @@ -31,8 +32,8 @@ public IThrowableProxy getThrowableProxy(); /** - * Return caller data associated with this event. Note that calling - * this event may trigger the computation of caller data. + * Return caller data associated with this event. Note that calling this event + * may trigger the computation of caller data. * * @return the caller data associated with this event. * Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/spi/LoggingEvent.java Fri Jun 12 23:00:55 2009 @@ -25,10 +25,10 @@ /** * The internal representation of logging events. When an affirmative decision * is made to log then a <code>LoggingEvent</code> instance is created. This - * instance is passed around to the different Logback components. + * instance is passed around to the different logback-classic components. * - * Writers of Logback components such as appenders should be aware of that - * some of the LoggingEvent fields are initialized lazily. Therefore, an + * Writers of logback-classic components such as appenders should be aware + * of that some of the LoggingEvent fields are initialized lazily. Therefore, an * appender wishing to output data to be later correctly read by a receiver, * must initialize "lazy" fields prior to writing them out. See the * {@link #prepareForDeferredProcessing()} method for the exact list. @@ -54,7 +54,7 @@ private String loggerName; private LoggerContext loggerContext; private LoggerContextVO loggerContextVO; - + /** * Level of logging event. * @@ -243,7 +243,8 @@ */ public StackTraceElement[] getCallerData() { if (callerDataArray == null) { - callerDataArray = CallerData.extract(new Throwable(), fqnOfLoggerClass, loggerContext.getMaxCallerDataDepth()); + callerDataArray = CallerData.extract(new Throwable(), fqnOfLoggerClass, + loggerContext.getMaxCallerDataDepth()); } return callerDataArray; } Added: logback/trunk/logback-site/src/site/pages/deadlock.html ============================================================================== --- (empty file) +++ logback/trunk/logback-site/src/site/pages/deadlock.html Fri Jun 12 23:00:55 2009 @@ -0,0 +1,79 @@ + + +logback-core/src/main/java/ch/qos/logback/core/AppenderBase.java: + public synchronized void doAppend(E eventObject) + +logback-core/src/main/java/ch/qos/logback/core/BasicStatusManager.java: + locks: + Object statusListLock + Object statusListenerListLock + exposition: to derived classes + +logback-core/src/main/java/ch/qos/logback/core/status/StatusBase.java: + locks: this + lock exposition: this + +logback-classic/src/main/java/ch/qos/logback/classic/selector/ContextJNDISelector.java: + locks: synchronizedContextMap + lock exposition: none + + +logback-classic/src/main/java/ch/qos/logback/classic/Logger.java + locks: synchronizedContextMap + lock exposition: none + +logback-classic/src/main/java/ch/qos/logback/classic/LoggerContext.java + locks: logger, + loggerCache should be syncronzied but is not + lock exposition: + +logback-classic/src/main/java/ch/qos/logback/classic/Logger.java: + * synchronized on 'this' (Logger) protecting against simultaneous + * only within addAppender which is synchronized 3) all the other methods + public synchronized void setLevel(Level newLevel) { + private synchronized void handleParentLevelChange(int newParentLevelInt) { + // this method MUST be synchronized. See comments on 'aai' field for further + public synchronized void addAppender(Appender<LoggingEvent> newAppender) { + + +logback-core/src/main/java/ch/qos/logback/core/joran/GenericConfigurator.java: + locks: context + lock exposition: none + + + + + * only within addAppender which is synchronized 3) all the other methods + public synchronized void setLevel(Level newLevel) { + private synchronized void handleParentLevelChange(int newParentLevelInt) { + // this method MUST be synchronized. See comments on 'aai' field for further + public synchronized void addAppender(Appender<LoggingEvent> newAppender) { + + + + +logback-core/src/main/java/ch/qos/logback/core/FileAppender.java: public synchronized void openFile(String file_name) throws IOException { + +logback-core/src/main/java/ch/qos/logback/core/net/SMTPAppenderBase.java: synchronized public void stop() { +logback-core/src/main/java/ch/qos/logback/core/net/SocketAppenderBase.java: synchronized (this) { + +logback-core/src/main/java/ch/qos/logback/core/WriterAppender.java: public synchronized void stop() { +logback-core/src/main/java/ch/qos/logback/core/WriterAppender.java: public synchronized void setWriter(Writer writer) { + +logback-classic/src/main/java/ch/qos/logback/classic/net/JMSQueueAppender.java: public synchronized void stop() { +logback-classic/src/main/java/ch/qos/logback/classic/net/JMSQueueAppender.java: // The synchronized modifier avoids concurrent append and close operations +logback-classic/src/main/java/ch/qos/logback/classic/net/JMSTopicAppender.java: public synchronized void stop() { +logback-classic/src/main/java/ch/qos/logback/classic/net/JMSTopicAppender.java: // The synchronized modifier avoids concurrent append and close operations + + +logback-core/src/main/java/ch/qos/logback/core/status/StatusBase.java: public synchronized void add(Status child) { +logback-core/src/main/java/ch/qos/logback/core/status/StatusBase.java: public synchronized boolean hasChildren() { +logback-core/src/main/java/ch/qos/logback/core/status/StatusBase.java: public synchronized Iterator<Status> iterator() { +logback-core/src/main/java/ch/qos/logback/core/status/StatusBase.java: public synchronized boolean remove(Status statusToRemove) { + + +logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java: synchronized (socketNodeList) { +logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java: synchronized(this) { +logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java: synchronized (socketNodeList) { +logback-classic/src/main/java/ch/qos/logback/classic/net/SimpleSocketServer.java: synchronized (socketNodeList) { +logback-classic/src/main/java/ch/qos/logback/classic/pattern/DateConverter.java: // the AppenderBase.doAppend is synchronized, we are should be Modified: logback/trunk/logback-site/src/site/pages/manual/appenders.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/appenders.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/appenders.html Fri Jun 12 23:00:55 2009 @@ -69,7 +69,7 @@ E as its only parameter. The actual type of E would vary depending on the logback module. Within the logback-classic module E would be of type <a - href="../apidocs/ch/qos/logback/classic/spi/LoggingEvent.html">LoggingEvent</a> + href="../apidocs/ch/qos/logback/classic/spi/ILoggingEvent.html">ILoggingEvent</a> and within the logback-access module it would be of type <a href="../apidocs/ch/qos/logback/access/spi/AccessEvent.html">AccessEvent</a>. The <code>doAppend()</code> method is perhaps the most important in @@ -303,6 +303,7 @@ import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.WriterAppender; import ch.qos.logback.core.layout.EchoLayout; @@ -311,9 +312,9 @@ public static void main(String[] args) throws Exception { LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory(); lc.reset(); // we want to override the default-config. - WriterAppender<LoggingEvent> writerAppender = new WriterAppender<LoggingEvent>(); + WriterAppender<ILoggingEvent> writerAppender = new WriterAppender<ILoggingEvent>(); writerAppender.setContext(lc); - writerAppender.setLayout(new EchoLayout<<LoggingEvent>()); + writerAppender.setLayout(new EchoLayout<<ILoggingEvent>()); OutputStream os = new FileOutputStream("exitWoes1.log"); writerAppender.setWriter(new OutputStreamWriter(os)); @@ -1254,7 +1255,9 @@ While logging events are generic in logback-core, within logback-classic they are always instances of - <code>LoggingEvent</code>. + <code>ILoggingEvent</code>. Logback-classic is nothing more than a + specialized processing pipleline handling instances of + <code>ILoggingEvent</code>. @@ -1266,8 +1269,12 @@ resources. In contrast, the <a href="../xref/ch/qos/logback/classic/net/SocketAppender.html"> <code>SocketAppender</code></a> is designed to log to a remote - entity by transmitting serialized <code>LoggingEvent</code> - objects over the wire. Remote logging is non-intrusive as far as + entity by transmitting serialized <code>ILoggingEvent</code> + instances over the wire. The actual type of the serialized event + is <a + href="../xref/ch/qos/logback/classic/spi/LoggingEventVO.html"><code>LoggingEventVO</code></a> + which implements the <code>ILoggingEvent</code> + interface. Nevertheless, remote logging is non-intrusive as far as the logging event is concerned. On the receiving end after de-serialization, the event can be logged as if it were generated locally. Multiple <code>SocketAppender</code> instances running of @@ -1732,37 +1739,41 @@ <h4>Comments on JMS appenders</h4> - - Transmitting a packet of information using JMS is certain to be substantially - slower then sending the same packet using raw TCP sockets. JMS vendors bragging - about the performance of their messaging platform tend to omit this simple fact. - Guaranteed store and forward messaging comes at a hefty price. - In return for increased cost, JMS messaging provides decoupling of - sender and receiver. As long as the JMS provider is reachable, messages - will eventually arrive at destination. - However, what if the JMS server is down or simply unreachable? - - - - According to the JMS specification, producers can mark a message as either - persistent or non-persistent. The persistent delivery mode instructs the JMS provider - to log the message to stable storage as part of the client's send operation, allowing - the message to survive provider crashes. JMS appenders do not set the delivery - mode of messages it produces because according to the JMS specification, - the delivery mode is considered as an administered property. - - - - Once a message reaches the JMS provider, the provider assumes the responsibility - of delivering it to its destination, relieving the client from this chore. - What if the JMS server is unreachable? The JMS API provides an - <code>ExceptionListener</code> interface to deal with this situation. - When the client runtime of the JMS provider detects a lost connection to the JMS server, - it calls the <code>onException()</code> method of the registered - <code>ExceptionListener</code>. Once notified of the problem, client code can attempt - to reestablish the connection. According to the section 4.3.8 of the JMS specification, - the provider should attempt to resolve connection problems prior to notifying the client. - The JMS appenders do not implement the <code>ExceptionListener</code> interface. + Transmitting a packet of information using JMS is certain to be + substantially slower then sending the same packet using raw TCP + sockets. JMS vendors bragging about the performance of their + messaging platform tend to omit this simple fact. Guaranteed + store and forward messaging comes at a hefty price. In return for + increased cost, JMS messaging provides decoupling of sender and + receiver. As long as the JMS provider is reachable, messages will + eventually arrive at destination. However, what if the JMS server + is down or simply unreachable? + + + According to the JMS specification, producers can mark a + message as either persistent or non-persistent. The persistent + delivery mode instructs the JMS provider to log the message to + stable storage as part of the client's send operation, allowing + the message to survive provider crashes. JMS appenders do not set + the delivery mode of messages it produces because according to the + JMS specification, the delivery mode is considered as an + administered property. + + + Once a message reaches the JMS provider, the provider assumes + the responsibility of delivering it to its destination, relieving + the client from this chore. What if the JMS server is + unreachable? The JMS API provides an + <code>ExceptionListener</code> interface to deal with this + situation. When the client runtime of the JMS provider detects a + lost connection to the JMS server, it calls the + <code>onException()</code> method of the registered + <code>ExceptionListener</code>. Once notified of the problem, + client code can attempt to reestablish the connection. According + to the section 4.3.8 of the JMS specification, the provider should + attempt to resolve connection problems prior to notifying the + client. The JMS appenders do not implement the + <code>ExceptionListener</code> interface. <a name="JMSTopicAppender"></a> @@ -1778,14 +1789,14 @@ Its most important method, <code>doAppend()</code> is listed below: -<div class="source"><pre>public void append(LoggingEvent event) { +<div class="source"><pre>public void append(ILoggingEvent event) { if (!isStarted()) { return; } try { ObjectMessage msg = topicSession.createObjectMessage(); - + Serializable so = pst.transform(event); msg.setObject(event); topicPublisher.publish(msg); successiveFailureCount = 0; @@ -1799,19 +1810,23 @@ }</pre></div> - The <code>isStarted()</code> method allows the appender to check whether - prerequisite conditions for its proper functioning, in particular the - availability of a valid and open <code>TopicConnection</code> and a - <code>TopicSession</code>, are fulfilled. If that is not the case, - the append method returns without performing any work. - If the prerequisite conditions are fulfilled, then the method - proceeds to publish the logging event. This is done by obtaining a - <code>javax.jms.ObjectMessage</code> from the <code>TopicSession</code> - and then setting its payload to the logging event received as - the input parameter. Once the payload of the message is set, it is - published. The fact that <code>LoggingEvent</code> is serializable - has its importance, as only Serializable objects can be - transported within an <code>ObjectMessage</code>. + The <code>isStarted()</code> method allows the appender to check + whether prerequisite conditions for its proper functioning, in + particular the availability of a valid and open + <code>TopicConnection</code> and a <code>TopicSession</code>, + are fulfilled. If that is not the case, the append method + returns without performing any work. If the prerequisite + conditions are fulfilled, then the method proceeds to publish + the logging event. This is done by obtaining a + <code>javax.jms.ObjectMessage</code> from the + <code>TopicSession</code> and then setting its payload to the + logging event received as the input parameter. Once the payload + of the message is set, it is published. Note that the + <code>ILoggingEvent</code> is transfomed to a serializable + object by a <a + href="../xref/ch/qos/logback/core/spi/PreSerializationTransformer.html">PreSerializationTransformer</a>. Only + Serializable objects can be transported within an + <code>ObjectMessage</code>. @@ -1828,12 +1843,12 @@ <div class="source"><pre>public void onMessage(javax.jms.Message message) { - LoggingEvent event; + ILoggingEvent event; try { if (message instanceof ObjectMessage) { ObjectMessage objectMessage = (ObjectMessage) message; - event = (LoggingEvent) objectMessage.getObject(); - Logger log = (Logger) LoggerFactory.getLogger(event.getLoggerRemoteView().getName()); + event = (ILoggingEvent) objectMessage.getObject(); + Logger log = (Logger) LoggerFactory.getLogger(event.getLoggerName()); log.callAppenders(event); } else { logger.warn("Received message is of type " + message.getJMSType() @@ -3216,26 +3231,30 @@ href="#WriteYourOwnAppender">Writing your own Appender</a></h3> - You can easily write your appender by sub-classing <code>AppenderBase</code>. - It handles support for filters, status among other functionality shared by most appenders. - The derived class only needs to implement one method, namely + You can easily write your appender by sub-classing + <code>AppenderBase</code>. It handles support for filters, status + among other functionality shared by most appenders. The derived + class only needs to implement one method, namely <code>append(Object eventObject)</code>. - The <code>CountingConsoleAppender</code>, which we list next, appends a limited - number of incoming events on the console. It shuts down after the limit is reached. - It uses a <code>Layout</code> to format the events and accepts a parameter, + The <code>CountingConsoleAppender</code>, which we list next, + appends a limited number of incoming events on the console. It + shuts down after the limit is reached. It uses a + <code>Layout</code> to format the events and accepts a parameter, thus a few more methods are needed. - Example 4.: <code>CountingConsoleAppender</code> (logback-examples/src/main/java/chapter4/CountingConsoleAppender.java) + Example 4.: + <code>CountingConsoleAppender</code> + (logback-examples/src/main/java/chapter4/CountingConsoleAppender.java) package chapter4; import ch.qos.logback.core.AppenderBase; import ch.qos.logback.core.Layout; -public class CountingConsoleAppender extends AppenderBase<LoggingEvent> { +public class CountingConsoleAppender extends AppenderBase<ILoggingEvent> { static int DEFAULT_LIMIT = 16; int counter = 0; int limit = DEFAULT_LIMIT; @@ -3261,7 +3280,7 @@ super.start(); } - public void append(LoggingEvent event) { + public void append(ILoggingEvent event) { if (counter >= limit) { return; Modified: logback/trunk/logback-site/src/site/pages/manual/architecture.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/architecture.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/architecture.html Fri Jun 12 23:00:55 2009 @@ -762,14 +762,14 @@ <h4>3. Create a <code>LoggingEvent</code> object</h4> - If the request passed the previous filters, logback will create a - <code>ch.qos.logback.classic.LoggingEvent</code> object containing - all the relevant parameters of the request, such as the logger of - the request, the request level, the message itself, the exception - that might have been passed along with the request, the current - time, the current thread, various data about the class that issued - the logging request and the <code>MDC</code>. Note that some of - these fields are initialized lazily, that is only when they are + If the request survivedy the previous filters, logback will + create a <code>ch.qos.logback.classic.LoggingEvent</code> object + containing all the relevant parameters of the request, such as the + logger of the request, the request level, the message itself, the + exception that might have been passed along with the request, the + current time, the current thread, various data about the class that + issued the logging request and the <code>MDC</code>. Note that some + of these fields are initialized lazily, that is only when they are actually needed. The <code>MDC</code> is used to decorate the logging request with additional contextual information. MDC is discussed in a <a href="mdc.html">subsequent chapter</a>. @@ -777,11 +777,11 @@ <h4>4. Invoking appenders</h4> After the creation of a <code>LoggingEvent</code> object, logback - invokes the <code>doAppend()</code> methods of all the applicable - appenders, that is, the appenders inherited from the logger context. + will invoke the <code>doAppend()</code> methods of all the + applicable appenders, that is, the appenders inherited from the + logger context. - All appenders shipped with the logback distribution extend the <code>AppenderBase</code> abstract class that implements the <code>doAppend</code> method in a synchronized block ensuring Modified: logback/trunk/logback-site/src/site/pages/manual/filters.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/filters.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/filters.html Fri Jun 12 23:00:55 2009 @@ -61,7 +61,7 @@ <code>Filter</code> objects all extend the <a href="../xref/ch/qos/logback/core/filter/Filter.html"><code>Filter</code></a> abstract class. The <code>decide(Object event)</code> method is - passed a newly created <code>LoggingEvent</code> object. + passed a newly created <code>ILoggingEvent</code> instance. <h3>Filter chains</h3> Modified: logback/trunk/logback-site/src/site/pages/manual/layouts.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/layouts.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/layouts.html Fri Jun 12 23:00:55 2009 @@ -66,8 +66,8 @@ <h2>Logback-classic</h2> Logback-classic is wired to processes only events of type - <a href="../xref/ch/qos/logback/classic/spi/LoggingEvent.html"> - <code>ch.qos.logback.classic.spi.LoggingEvent</code></a>. This + <a href="../xref/ch/qos/logback/classic/spi/ILoggingEvent.html"> + <code>ch.qos.logback.classic.spi.ILoggingEvent</code></a>. This fact will apparent for the remaining of this section. @@ -92,59 +92,51 @@ <div class="source"><pre>package chapter5; -import ch.qos.logback.classic.spi.LoggingEvent; +import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.LayoutBase; -public class MySampleLayout extends LayoutBase<LoggingEvent> { +public class MySampleLayout extends LayoutBase<ILoggingEvent> { - public String doLayout(LoggingEvent event) { + public String doLayout(ILoggingEvent event) { StringBuffer sbuf = new StringBuffer(128); - sbuf.append(event.getTimeStamp() - LoggingEvent.getStartTime()); + sbuf.append(event.getTimeStamp() - event.getLoggingContextVO.getBirthTime()); sbuf.append(" "); sbuf.append(event.getLevel()); sbuf.append(" ["); sbuf.append(event.getThreadName()); sbuf.append("] "); - sbuf.append(event.getLoggerRemoteView().getName()); + sbuf.append(event.getLoggerName(); sbuf.append(" - "); sbuf.append(event.getFormattedMessage()); - sbuf.append(LINE_SEP); + sbuf.append(CoreConstants.LINE_SEP); return sbuf.toString(); } }</pre></div> - - Note that <code>MySampleLayout</code> extends <a - href="../xref/ch/qos/logback/core/LayoutBase.html"> - <code>LayoutBase</code></a>. This class manages state shared by - all <code>Layout</code> classes, such as whether the layout is - started or stopped, header, footer and content type data. It - allows the developer to concentrate on the formatting she - expects from her <code>Layout</code>. Note that the - <code>LayoutBase</code> class is generic. In its class - declaration, <code>MySampleLayout</code> extends a typed - <code>LayoutBase</code>, - <code>LayoutBase<LoggingEvent></code>, instead of generic - one. + Note that <code>MySampleLayout</code> extends <a + href="../xref/ch/qos/logback/core/LayoutBase.html"> + <code>LayoutBase</code></a>. This class manages state shared by + all <code>Layout</code> classes, such as whether the layout is + started or stopped, header, footer and content type data. It + allows the developer to concentrate on the formatting expected + from his/her <code>Layout</code>. Note that the + <code>LayoutBase</code> class is generic. In its class + declaration, <code>MySampleLayout</code> extends + <code>LayoutBase<ILoggingEvent></code>. - The <code>doLayout(LoggingEvent event)</code> method, i.e. the + The <code>doLayout(ILoggingEvent event)</code> method, i.e. the only method in <code>MySampleLayout</code>, begins by instantiating a <code>StringBuffer</code>. It proceeds by adding various fields of the event parameter. The Texan from Texas was careful to print the formatted form of the message. This is - important when there are one or more parameters passed along with + significant in case one or more parameters were passed along with the logging request. - In the above listing of the <code>Layout</code> class, the - <code>LINE_SEP</code> field is inherited from the - <code>Layout</code> interface. It refers to the value returned by - <code>System.getProperty("line.separator")</code> method, that is - system dependent line separator character(s). After adding these - system dependent character(s), the <code>doLayout()</code> method - converts <code>sbuf</code> to <code>String</code> and returns the - resulting value. + After adding these various characters to the string buffer, the + <code>doLayout()</code> method converts the buffer into + <code>String</code> and returns the resulting value. In the above example, the <code>doLayout</code> method ignores @@ -211,10 +203,10 @@ package chapter5; -import ch.qos.logback.classic.spi.LoggingEvent; +import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.LayoutBase; -public class MySampleLayout2 extends LayoutBase<LoggingEvent> { +public class MySampleLayout2 extends LayoutBase<ILoggingEvent> { String prefix = null; boolean printThreadName = true; @@ -227,12 +219,12 @@ this.printThreadName = printThreadName; } - public String doLayout(LoggingEvent event) { + public String doLayout(ILoggingEvent event) { StringBuffer sbuf = new StringBuffer(128); if (prefix != null) { sbuf.append(prefix + ": "); } - sbuf.append(event.getTimeStamp() - LoggingEvent.getStartTime()); + sbuf.append(event.getTimeStamp() - event.getLoggerContextVO().getBirthTime()); sbuf.append(" "); sbuf.append(event.getLevel()); if (printThreadName) { @@ -242,7 +234,7 @@ } else { sbuf.append(" "); } - sbuf.append(event.getLoggerRemoteView().getName()); + sbuf.append(event.getLoggerName()); sbuf.append(" - "); sbuf.append(event.getFormattedMessage()); sbuf.append(LINE_SEP); @@ -327,7 +319,7 @@ layout.setPattern("%-5level [%thread]: %message%n"); layout.start(); - ConsoleAppender<LoggingEvent> appender = new ConsoleAppender<LoggingEvent>(); + ConsoleAppender<ILoggingEvent> appender = new ConsoleAppender<ILoggingEvent>(); appender.setContext(rootLogger.getLoggerContext()); appender.setLayout(layout); appender.start(); @@ -1379,19 +1371,20 @@ Building a custom conversion specifier consists of two steps. - First, you must sub-class the <code>Converter</code> class. <a - href="../xref/ch/qos/logback/core/pattern/Converter.html"> - <code>Converter</code></a> objects are responsible for extracting - information out of <code>LoggingEvent</code> objects and returning - it as String. For example, the + First, you must extend the <code>ClassicConverter</code> + class. <a + href="../xref/ch/qos/logback/classic/pattern/ClassicConverter.html"> + <code>ClassicConverter</code></a> objects are responsible for + extracting information out of <code>ILoggingEvent</code> instances + and producing a String. For example, the <a href="../xref/ch/qos/logback/classic/pattern/LoggerConverter.html"> <code>LoggerConverter</code></a>, the converter underlying the - %logger conversion word, extracts the name of the logger from the - <code>LoggingEvent</code> and returns it as a String. It might + %logger conversion word, extracts the name of the logger from + <code>ILoggingEvent</code> and returns it as a String. It might abbreviate the logger name in the process. - Let us say that our customized <code>Converter</code> colors - the level of the logging event, according to ANSI terminal + Let us say that our customized <code>ClassicConverter</code> + colors the level of the logging event, according to ANSI terminal conventions. Here is a possible implementation: Example 5.4: Sample Converter Example @@ -1401,7 +1394,7 @@ import ch.qos.logback.classic.Level; import ch.qos.logback.classic.pattern.ClassicConverter; -import ch.qos.logback.classic.spi.LoggingEvent; +import ch.qos.logback.classic.spi.ILoggingEvent; public class MySampleConverter extends ClassicConverter { @@ -1411,7 +1404,7 @@ private static final String WARN_COLOR = "\u001b[0;33m"; @Override - public String convert(LoggingEvent event) { + public String convert(ILoggingEvent event) { StringBuffer sbuf = new StringBuffer(); sbuf.append(getColor(event.getLevel())); sbuf.append(event.getLevel()); Modified: logback/trunk/logback-site/src/site/pages/manual/mdc.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/mdc.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/mdc.html Fri Jun 12 23:00:55 2009 @@ -107,7 +107,6 @@ import org.slf4j.MDC; import ch.qos.logback.classic.PatternLayout; -import ch.qos.logback.classic.spi.LoggingEvent; import ch.qos.logback.core.ConsoleAppender; public class SimpleMDC { Modified: logback/trunk/logback-site/src/site/pages/manual/migrationFromLog4j.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/migrationFromLog4j.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/migrationFromLog4j.html Fri Jun 12 23:00:55 2009 @@ -42,15 +42,16 @@ and layouts exist in both frameworks and serve identical purposes. Similarly, the most important internal data-structure, namely <code>LoggingEvent</code> exists in both frameworks with - rather similar but non-identical implementations. Most of the - changes requried in migrating log4j components to logback-classic - are related to differences in implementation of the - <code>LoggingEvent</code> class. Rest assured, these differences - are rather limited. If in spite of your best efforts you are - unable to migrate any given log4j component to logback-classic, do - post a question on the <a href="../mailinglist.html">logback-dev - mailing list</a>. A logback developper should be able to provide - guidance. + rather similar but non-identical implementations. Most notably, In + logback-classic <code>LoggingEvent</code> implements the + <code>ILoggingEvent</code> interface. Most of the changes requried + in migrating log4j components to logback-classic are related to + differences in implementation of the <code>LoggingEvent</code> + class. Rest assured, these differences are rather limited. If in + spite of your best efforts you are unable to migrate any given + log4j component to logback-classic, do post a question on the <a + href="../mailinglist.html">logback-dev mailing list</a>. A logback + developper should be able to provide guidance. @@ -90,12 +91,12 @@ package chapter11; -import ch.qos.logback.classic.spi.LoggingEvent; +import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.LayoutBase; -public class TrivialLogbackLayout extends LayoutBase<LoggingEvent> { +public class TrivialLogbackLayout extends LayoutBase<ILoggingEvent> { - public String doLayout(LoggingEvent loggingEvent) { + public String doLayout(ILoggingEvent loggingEvent) { return loggingEvent.getMessage(); } } @@ -105,7 +106,7 @@ <code>format</code>() in log4j. The <code>ignoresThrowable</code>() method is not needed and has no equivalent in logback-classic. Note that a logback-classic layout must extend the - <code>LayoutBase<LoggingEvent></code> class. + <code>LayoutBase<ILoggingEvent></code> class. The <code>activateOptions</code>() method merits further @@ -161,10 +162,10 @@ package chapter11; -import ch.qos.logback.classic.spi.LoggingEvent; +import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.AppenderBase; -public class TrivialLogbackAppender extends AppenderBase<LoggingEvent> { +public class TrivialLogbackAppender extends AppenderBase<ILoggingEvent> { @Override public void start() { @@ -176,7 +177,7 @@ } @Override - protected void append(LoggingEvent loggingevent) { + protected void append(ILoggingEvent loggingevent) { // note that AppenderBase.doAppend will invoke this method only if // this appender was successfully started.

1 0

License (again)
by Ralph Goers 12 Jun '09

12 Jun '09

It occurred to me that any custom Appenders written for Logback must be licensed under the LGPL since they have to extend Logback base classes. Is it possible to change the license for Appender, AppenderBase and UnsynchronizedAppenderBase to something more liberal? I know my employer wouldn't be too thrilled to have to distribute the source for Appenders along with their product.

2 4