- logback-dev - mailman3.qos.ch

svn commit: r1842 - in logback/trunk/logback-core/src: main/java/ch/qos/logback/core test/java/ch/qos/logback/core test/java/ch/qos/logback/core/appender
by noreply.ceki＠qos.ch 17 Oct '08

17 Oct '08

Author: ceki Date: Fri Oct 17 23:42:28 2008 New Revision: 1842 Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/PackageTest.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/WriterAppenderTest.java Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/WriterAppender.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/AllCoreTest.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/ConsoleAppenderTest.java Log: Fixing LBCORE-55 In WriterAppender, getPresentationFooter and getFileFooter are now printed in the correct order, presentation footer first, file footer last. Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/WriterAppender.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/WriterAppender.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/WriterAppender.java Fri Oct 17 23:42:28 2008 @@ -17,12 +17,12 @@ import ch.qos.logback.core.status.ErrorStatus; /** - * WriterAppender appends events to a hava.io.Writer. - * This class provides basic services that other appenders build upon. + * WriterAppender appends events to a hava.io.Writer. This class provides basic + * services that other appenders build upon. + * + * For more information about this appender, please refer to the online manual + * at http://logback.qos.ch/manual/appenders.html#WriterAppender * - * For more information about this appender, please refer to the online manual at - * http://logback.qos.ch/manual/appenders.html#WriterAppender - * * @author Ceki Gülcü */ public class WriterAppender<E> extends AppenderBase<E> { @@ -97,16 +97,14 @@ public void start() { int errors = 0; if (this.layout == null) { - addStatus( - new ErrorStatus("No layout set for the appender named \"" + name - + "\".", this)); + addStatus(new ErrorStatus("No layout set for the appender named \"" + + name + "\".", this)); errors++; } if (this.writer == null) { - addStatus( - new ErrorStatus("No writer set for the appender named \"" + name - + "\".", this)); + addStatus(new ErrorStatus("No writer set for the appender named \"" + + name + "\".", this)); errors++; } // only error free appenders should be activated @@ -147,9 +145,8 @@ this.writer.close(); this.writer = null; } catch (IOException e) { - addStatus( - new ErrorStatus("Could not close writer for WriterAppener.", this, - e)); + addStatus(new ErrorStatus("Could not close writer for WriterAppener.", + this, e)); } } } @@ -205,48 +202,48 @@ } void writeHeader() { - if (layout != null) { - String h = layout.getFileHeader(); + if (layout != null && (this.writer != null)) { + try { - if ((h != null) && (this.writer != null)) { - try { + String h = layout.getFileHeader(); + if (h != null) { this.writer.write(h); - String ph = layout.getPresentationHeader(); - if (ph != null) { - this.writer.write(ph); - } - // append a line separator. This should be useful in most cases and should - // not hurt. + } + String ph = layout.getPresentationHeader(); + if (ph != null) { + this.writer.write(ph); + } + // If at least one of file header or presentation header were not null, then append a line separator. + // This should be useful in most cases and should not hurt. + if ((h != null) || (ph != null)) { this.writer.write(Layout.LINE_SEP); this.writer.flush(); - } catch (IOException ioe) { - this.started = false; - addStatus(new ErrorStatus( - "Failed to write header for appender named [" + name + "].", - this, ioe)); } + } catch (IOException ioe) { + this.started = false; + addStatus(new ErrorStatus("Failed to write header for appender named [" + + name + "].", this, ioe)); } } } void writeFooter() { - if (layout != null) { - String h = layout.getFileFooter(); - if ((h != null) && (this.writer != null)) { - try { + if (layout != null && this.writer != null) { + try { + String pf = layout.getPresentationFooter(); + if (pf != null) { + this.writer.write(pf); + } + String h = layout.getFileFooter(); + if (h != null) { this.writer.write(h); - String pf = layout.getPresentationFooter(); - if (pf != null) { - this.writer.write(pf); - } - // flushing is mandatory if the writer is not later closed. - this.writer.flush(); - } catch (IOException ioe) { - this.started = false; - addStatus(new ErrorStatus( - "Failed to write footer for appender named [" + name + "].", - this, ioe)); } + // flushing is mandatory if the writer is not later closed. + this.writer.flush(); + } catch (IOException ioe) { + this.started = false; + addStatus(new ErrorStatus("Failed to write footer for appender named [" + + name + "].", this, ioe)); } } } @@ -258,7 +255,7 @@ * be closed when the appender instance is closed. * * @param writer - * An already opened Writer. + * An already opened Writer. */ public synchronized void setWriter(Writer writer) { // close any previously opened writer Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/AllCoreTest.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/AllCoreTest.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/AllCoreTest.java Fri Oct 17 23:42:28 2008 @@ -20,6 +20,7 @@ suite.addTest(ch.qos.logback.core.util.PackageTest.suite()); suite.addTest(ch.qos.logback.core.helpers.PackageTest.suite()); suite.addTest(ch.qos.logback.core.pattern.PackageTest.suite()); + suite.addTest(ch.qos.logback.core.PackageTest.suite()); suite.addTest(ch.qos.logback.core.joran.PackageTest.suite()); suite.addTest(ch.qos.logback.core.appender.PackageTest.suite()); suite.addTest(ch.qos.logback.core.rolling.PackageTest.suite()); Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/PackageTest.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/PackageTest.java Fri Oct 17 23:42:28 2008 @@ -0,0 +1,15 @@ +package ch.qos.logback.core; + +import junit.framework.JUnit4TestAdapter; +import junit.framework.Test; +import junit.framework.TestCase; +import junit.framework.TestSuite; + +public class PackageTest extends TestCase { + + public static Test suite() { + TestSuite suite = new TestSuite(); + suite.addTest(new JUnit4TestAdapter(WriterAppenderTest.class)); + return suite; + } +} Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/WriterAppenderTest.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/WriterAppenderTest.java Fri Oct 17 23:42:28 2008 @@ -0,0 +1,114 @@ +/** + * Logback: the generic, reliable, fast and flexible logging framework. + * + * Copyright (C) 2000-2008, QOS.ch + * + * This library is free software, you can redistribute it and/or modify it under + * the terms of the GNU Lesser General Public License as published by the Free + * Software Foundation. + */ + +package ch.qos.logback.core; + + +import static org.junit.Assert.*; + +import java.io.StringWriter; +import java.io.Writer; + +import org.junit.After; +import org.junit.Before; +import org.junit.Test; + +import ch.qos.logback.core.pattern.parser.SamplePatternLayout; + +public class WriterAppenderTest { + + Context context = new ContextBase(); + + @Before + public void setUp() throws Exception { + } + + @After + public void tearDown() throws Exception { + } + + @Test + public void smoke() { + String FILE_HEADER = "FILE_HEADER "; + String PRESENTATION_HEADER = "PRESENTATION_HEADER"; + String PRESENTATION_FOOTER = "PRESENTATION_FOOTER "; + String FILE_FOOTER = "FILE_FOOTER"; + headerFooterCheck(FILE_HEADER, PRESENTATION_HEADER, PRESENTATION_FOOTER, FILE_FOOTER); + } + + @Test + public void nullFileHeader() { + String FILE_HEADER = null; + String PRESENTATION_HEADER = "PRESENTATION_HEADER"; + String PRESENTATION_FOOTER = "PRESENTATION_FOOTER "; + String FILE_FOOTER = "FILE_FOOTER"; + headerFooterCheck(FILE_HEADER, PRESENTATION_HEADER, PRESENTATION_FOOTER, FILE_FOOTER); + } + + @Test + public void nullPresentationHeader() { + String FILE_HEADER = "FILE_HEADER "; + String PRESENTATION_HEADER = null; + String PRESENTATION_FOOTER = "PRESENTATION_FOOTER "; + String FILE_FOOTER = "FILE_FOOTER"; + headerFooterCheck(FILE_HEADER, PRESENTATION_HEADER, PRESENTATION_FOOTER, FILE_FOOTER); + } + + @Test + public void nullPresentationFooter() { + String FILE_HEADER = "FILE_HEADER "; + String PRESENTATION_HEADER = "PRESENTATION_HEADER"; + String PRESENTATION_FOOTER = null; + String FILE_FOOTER = "FILE_FOOTER"; + headerFooterCheck(FILE_HEADER, PRESENTATION_HEADER, PRESENTATION_FOOTER, FILE_FOOTER); + } + + @Test + public void nullFileFooter() { + String FILE_HEADER = "FILE_HEADER "; + String PRESENTATION_HEADER = "PRESENTATION_HEADER"; + String PRESENTATION_FOOTER = "PRESENTATION_FOOTER "; + String FILE_FOOTER = null; + headerFooterCheck(FILE_HEADER, PRESENTATION_HEADER, PRESENTATION_FOOTER, FILE_FOOTER); + } + + public void headerFooterCheck(String fileHeader, String presentationHeader, String presentationFooter, String fileFooter) { + WriterAppender<Object> wa = new WriterAppender<Object>(); + wa.setContext(context); + Writer sw = new StringWriter(); + + SamplePatternLayout<Object> spl = new SamplePatternLayout<Object>(); + spl.setContext(context); + + spl.setFileHeader(fileHeader); + spl.setPresentationHeader(presentationHeader); + spl.setPresentationFooter(presentationFooter); + spl.setFileFooter(fileFooter); + + spl.start(); + + wa.setLayout(spl); + wa.setWriter(sw); + wa.start(); + + wa.stop(); + String result = sw.toString(); + + String expectedHeader = emtptyIfNull(fileHeader) + emtptyIfNull(presentationHeader); + assertTrue(result, result.startsWith(expectedHeader)); + + String expectedFooter = emtptyIfNull(presentationFooter) + emtptyIfNull(fileFooter); + assertTrue(result, result.endsWith(expectedFooter)); + } + + String emtptyIfNull(String s) { + return s == null ? "" : s; + } +} Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/ConsoleAppenderTest.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/ConsoleAppenderTest.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/ConsoleAppenderTest.java Fri Oct 17 23:42:28 2008 @@ -85,12 +85,12 @@ public void testClose() { ConsoleAppender<Object> ca = (ConsoleAppender<Object>) getAppender(); DummyLayout<Object> dummyLayout = new DummyLayout<Object>(); - dummyLayout.setFileFooter("closed"); + dummyLayout.setFileFooter("CLOSED"); ca.setLayout(dummyLayout); ca.start(); ca.doAppend(new Object()); ca.stop(); - assertEquals(DummyLayout.DUMMY + "closed", tee.toString()); + assertEquals(DummyLayout.DUMMY + "CLOSED", tee.toString()); }

1 0

[JIRA] Resolved: (LBGENERAL-14) Log4j bridge TRACE level
by Ceki Gulcu (JIRA) 17 Oct '08

17 Oct '08

[ http://jira.qos.ch/browse/LBGENERAL-14?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu resolved LBGENERAL-14. --------------------------------- Resolution: Won't Fix The log4j bridge has moved into the SLF4J project. Moreover, the bug you mention has been fixed there. See also http://bugzilla.slf4j.org/show_bug.cgi?id=74 > Log4j bridge TRACE level > ------------------------ > > Key: LBGENERAL-14 > URL: http://jira.qos.ch/browse/LBGENERAL-14 > Project: logback-general > Issue Type: Bug > Components: build-structure > Affects Versions: unspecified > Environment: Operating System: Linux > Platform: PC > Reporter: Markus Wolf > Assignee: Logback dev list > > While trying to use logbacks log4j bridge to have JBoss EmbeddedEJB3 to log I stumbled over the following stacktrace. > I use logback-*-0.9.7 and slf4j-*-1.4.0. > Caused by: java.lang.IllegalStateException: Unknown Priority TRACE > at org.apache.log4j.Category.priorityToLevel(Category.java:351) > at org.apache.log4j.Category.log(Category.java:332) > at org.jboss.logging.Log4jLoggerPlugin.trace(Log4jLoggerPlugin.java:119) > at org.jboss.logging.Logger.trace(Logger.java:152) > at org.jboss.kernel.plugins.bootstrap.AbstractBootstrap.run(AbstractBootstrap.java:93) > at org.jboss.ejb3.embedded.EJB3StandaloneBootstrap.createKernel(EJB3StandaloneBootstrap.java:422) > at org.jboss.ejb3.embedded.EJB3StandaloneBootstrap.boot(EJB3StandaloneBootstrap.java:375) -- 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

reducing resource contention in logback
by Ceki Gulcu 17 Oct '08

17 Oct '08

Hello all, Ralph and I had a lengthy chat discussing his contribution in LBCLASSIC-35 http://jira.qos.ch/browse/LBCLASSIC-35 For the public record, here is a brief summary of the exchange. His premise is that by carefully modifying synchronization in the AppenderBase and Logger classes we can significantly reduce contention among various threads using logback. The changes must preserve logging event atomicity. For example, if event0 consist of a message m0 and exception e0, and event1 consist of message m1, when an appender writes event0 and event1, possibly sent by different threads, the output must never be m0,m1,e0 but always m0,e0,m1 or alternatively m1,m0,e0. In other words, event intermingling is disallowed even if event ordering is not guaranteed. Raph modified the Logger class so that iterating on the appenders is done without locking. He currently uses ConcurrentHashMap. I think that CopyOnWriteArrayList would also work fine and result in simpler code. Ralph has also modified the doAppend method in AppenderBase pushing the synchronization point to within each derived appender class. Thus it becomes the responsibility of each appender to manage its own synchronization. These changes open the way for threads which support concurrent calls to be invoked without any contention by multiple threads. Of course, the underlying resource, where the logging output is eventually written to, still remains as a contention point. Cheers, -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

1 0

svn commit: r1841 - logback/trunk/logback-classic/src/main/java/org/slf4j/impl
by noreply.ceki＠qos.ch 17 Oct '08

17 Oct '08

Author: ceki Date: Fri Oct 17 21:44:30 2008 New Revision: 1841 Modified: logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java Log: logback 0.9.10 targets SLF4J 1.5.5 Modified: logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java (original) +++ logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java Fri Oct 17 21:44:30 2008 @@ -48,12 +48,12 @@ public static final StaticLoggerBinder SINGLETON = new StaticLoggerBinder(); /** - * Version tag used to check compatibility. The value of this field is - * modified with each release. + * Declare the version of the SLF4J API this implementation is compiled against. + * The value of this field is usually modified with each release. */ - //to avoid constant folding by the compiler, VERSION field should *not* be final - public static String VERSION = "1.5.4-SNAPSHOT"; - + // to avoid constant folding by the compiler, this field must *not* be final + public static String REQUESTED_API_VERSION = "1.5.5"; // !final + private static final String loggerFactoryClassStr = ContextSelector.class .getName();

1 0

[JIRA] Commented: (LBCLASSIC-35) Deadlock when running on multiple core processors
by Ceki Gulcu (JIRA) 17 Oct '08

17 Oct '08

[ http://jira.qos.ch/browse/LBCLASSIC-35?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBCLASSIC-35: ------------------------------------- I think we should talk over your patch over the phone or via IRC. > Deadlock when running on multiple core processors > ------------------------------------------------- > > Key: LBCLASSIC-35 > URL: http://jira.qos.ch/browse/LBCLASSIC-35 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: Windows > Platform: PC > Reporter: Toni Heimala > Assignee: Ceki Gulcu > Priority: Blocker > Attachments: patch.txt, patch2.txt > > > When you run logging into same file from many threads on a system that has more than one physical processor (Dual Core for example), a deadlock will occur after a while. This can not be reproduced on HyperThreading processors. Here's an example program that will demonstrate the behavior: > ----------------------------- > Main.java > ----------------------------- > import java.util.Date; > import java.util.concurrent.ScheduledThreadPoolExecutor; > import java.util.concurrent.TimeUnit; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > import ch.qos.logback.classic.LoggerContext; > import ch.qos.logback.classic.joran.JoranConfigurator; > import ch.qos.logback.core.joran.spi.JoranException; > public class Main extends Thread > { > private final static String LOGGER_CONFIGURATION_FILE = "logger.xml"; > private final Logger logger = LoggerFactory.getLogger(Main.class); > > private final long start; > > public Main() > throws JoranException > { > start = new Date().getTime(); > LoggerContext lc = (LoggerContext)LoggerFactory.getILoggerFactory(); > JoranConfigurator configurator = new JoranConfigurator(); > lc.shutdownAndReset(); > configurator.setContext(lc); > configurator.doConfigure(LOGGER_CONFIGURATION_FILE); > } > > public void start() > { > ScheduledThreadPoolExecutor ex1 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex2 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex3 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex4 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex5 = new ScheduledThreadPoolExecutor(1); > ex1.scheduleAtFixedRate(new Task("EX1"), 10, 10, TimeUnit.MICROSECONDS); > ex2.scheduleAtFixedRate(new Task("EX2"), 10, 10, TimeUnit.MICROSECONDS); > ex3.scheduleAtFixedRate(new Task("EX3"), 10, 10, TimeUnit.MICROSECONDS); > ex4.scheduleAtFixedRate(new Task("EX4"), 10, 10, TimeUnit.MICROSECONDS); > ex5.scheduleAtFixedRate(new Task("EX5"), 10, 10, TimeUnit.MICROSECONDS); > > super.start(); > } > > public void run() > { > try > { > while(true) > { > logger.debug("[MAIN] {}", new Date().getTime() - start); > Thread.sleep(10); > } > } > catch (InterruptedException e) > { > logger.info("[MAIN]: Interrupted: {}", e.getMessage()); > } > } > > public static void main(String[] args) > { > try > { > Main main = new Main(); > main.start(); > } > catch (JoranException e) > { > System.out.println("Failed to load application: " + e.getMessage()); > } > } > } > ------------------------------- > Task.java > ------------------------------- > import java.util.Date; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > public class Task implements Runnable > { > private final Logger logger = LoggerFactory.getLogger(Task.class); > private final Logger logger_main = LoggerFactory.getLogger(Main.class); > private final String name; > private final long start; > > public Task(final String name) > { > this.name = name; > start = new Date().getTime(); > } > public void run() > { > logger.debug("[{}] {}", name, new Date().getTime() - start); > logger_main.debug("[MAIN] - [{}] {}", name, new Date().getTime() - start); > } > } -- 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

3 2

[JIRA] Issue Comment Edited: (LBCLASSIC-35) Deadlock when running on multiple core processors
by Ralph Goers (JIRA) 16 Oct '08

16 Oct '08

[ http://jira.qos.ch/browse/LBCLASSIC-35?page=com.atlassian.jira.plugin.syste… ] Ralph Goers edited comment on LBCLASSIC-35 at 10/16/08 9:56 PM: ---------------------------------------------------------------- Updated patch. This one makes the Appender name required and immutable, removes all the synchronization from Logger while calling Appenders and makes sure that an AppenderAttachableImpl is always attached to the Logger eliminating any race conditions that might occur during reconfiguration. was (Author: ralphgoers): Updated patch. This one makes the Appender name required and immutable, removes all the synchronization from Logger and makes sure that an AppenderAttachableImpl is always attached to the Logger eliminating any race conditions that might occur during reconfiguration. > Deadlock when running on multiple core processors > ------------------------------------------------- > > Key: LBCLASSIC-35 > URL: http://jira.qos.ch/browse/LBCLASSIC-35 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: Windows > Platform: PC > Reporter: Toni Heimala > Assignee: Ceki Gulcu > Priority: Blocker > Attachments: patch.txt, patch2.txt > > > When you run logging into same file from many threads on a system that has more than one physical processor (Dual Core for example), a deadlock will occur after a while. This can not be reproduced on HyperThreading processors. Here's an example program that will demonstrate the behavior: > ----------------------------- > Main.java > ----------------------------- > import java.util.Date; > import java.util.concurrent.ScheduledThreadPoolExecutor; > import java.util.concurrent.TimeUnit; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > import ch.qos.logback.classic.LoggerContext; > import ch.qos.logback.classic.joran.JoranConfigurator; > import ch.qos.logback.core.joran.spi.JoranException; > public class Main extends Thread > { > private final static String LOGGER_CONFIGURATION_FILE = "logger.xml"; > private final Logger logger = LoggerFactory.getLogger(Main.class); > > private final long start; > > public Main() > throws JoranException > { > start = new Date().getTime(); > LoggerContext lc = (LoggerContext)LoggerFactory.getILoggerFactory(); > JoranConfigurator configurator = new JoranConfigurator(); > lc.shutdownAndReset(); > configurator.setContext(lc); > configurator.doConfigure(LOGGER_CONFIGURATION_FILE); > } > > public void start() > { > ScheduledThreadPoolExecutor ex1 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex2 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex3 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex4 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex5 = new ScheduledThreadPoolExecutor(1); > ex1.scheduleAtFixedRate(new Task("EX1"), 10, 10, TimeUnit.MICROSECONDS); > ex2.scheduleAtFixedRate(new Task("EX2"), 10, 10, TimeUnit.MICROSECONDS); > ex3.scheduleAtFixedRate(new Task("EX3"), 10, 10, TimeUnit.MICROSECONDS); > ex4.scheduleAtFixedRate(new Task("EX4"), 10, 10, TimeUnit.MICROSECONDS); > ex5.scheduleAtFixedRate(new Task("EX5"), 10, 10, TimeUnit.MICROSECONDS); > > super.start(); > } > > public void run() > { > try > { > while(true) > { > logger.debug("[MAIN] {}", new Date().getTime() - start); > Thread.sleep(10); > } > } > catch (InterruptedException e) > { > logger.info("[MAIN]: Interrupted: {}", e.getMessage()); > } > } > > public static void main(String[] args) > { > try > { > Main main = new Main(); > main.start(); > } > catch (JoranException e) > { > System.out.println("Failed to load application: " + e.getMessage()); > } > } > } > ------------------------------- > Task.java > ------------------------------- > import java.util.Date; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > public class Task implements Runnable > { > private final Logger logger = LoggerFactory.getLogger(Task.class); > private final Logger logger_main = LoggerFactory.getLogger(Main.class); > private final String name; > private final long start; > > public Task(final String name) > { > this.name = name; > start = new Date().getTime(); > } > public void run() > { > logger.debug("[{}] {}", name, new Date().getTime() - start); > logger_main.debug("[MAIN] - [{}] {}", name, new Date().getTime() - start); > } > } -- 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] Updated: (LBCLASSIC-35) Deadlock when running on multiple core processors
by Ralph Goers (JIRA) 16 Oct '08

16 Oct '08

[ http://jira.qos.ch/browse/LBCLASSIC-35?page=com.atlassian.jira.plugin.syste… ] Ralph Goers updated LBCLASSIC-35: --------------------------------- Attachment: patch2.txt Updated patch. This one makes the Appender name required and immutable, removes all the synchronization from Logger and makes sure that an AppenderAttachableImpl is always attached to the Logger eliminating any race conditions that might occur during reconfiguration. > Deadlock when running on multiple core processors > ------------------------------------------------- > > Key: LBCLASSIC-35 > URL: http://jira.qos.ch/browse/LBCLASSIC-35 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: Windows > Platform: PC > Reporter: Toni Heimala > Assignee: Ceki Gulcu > Priority: Blocker > Attachments: patch.txt, patch2.txt > > > When you run logging into same file from many threads on a system that has more than one physical processor (Dual Core for example), a deadlock will occur after a while. This can not be reproduced on HyperThreading processors. Here's an example program that will demonstrate the behavior: > ----------------------------- > Main.java > ----------------------------- > import java.util.Date; > import java.util.concurrent.ScheduledThreadPoolExecutor; > import java.util.concurrent.TimeUnit; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > import ch.qos.logback.classic.LoggerContext; > import ch.qos.logback.classic.joran.JoranConfigurator; > import ch.qos.logback.core.joran.spi.JoranException; > public class Main extends Thread > { > private final static String LOGGER_CONFIGURATION_FILE = "logger.xml"; > private final Logger logger = LoggerFactory.getLogger(Main.class); > > private final long start; > > public Main() > throws JoranException > { > start = new Date().getTime(); > LoggerContext lc = (LoggerContext)LoggerFactory.getILoggerFactory(); > JoranConfigurator configurator = new JoranConfigurator(); > lc.shutdownAndReset(); > configurator.setContext(lc); > configurator.doConfigure(LOGGER_CONFIGURATION_FILE); > } > > public void start() > { > ScheduledThreadPoolExecutor ex1 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex2 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex3 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex4 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex5 = new ScheduledThreadPoolExecutor(1); > ex1.scheduleAtFixedRate(new Task("EX1"), 10, 10, TimeUnit.MICROSECONDS); > ex2.scheduleAtFixedRate(new Task("EX2"), 10, 10, TimeUnit.MICROSECONDS); > ex3.scheduleAtFixedRate(new Task("EX3"), 10, 10, TimeUnit.MICROSECONDS); > ex4.scheduleAtFixedRate(new Task("EX4"), 10, 10, TimeUnit.MICROSECONDS); > ex5.scheduleAtFixedRate(new Task("EX5"), 10, 10, TimeUnit.MICROSECONDS); > > super.start(); > } > > public void run() > { > try > { > while(true) > { > logger.debug("[MAIN] {}", new Date().getTime() - start); > Thread.sleep(10); > } > } > catch (InterruptedException e) > { > logger.info("[MAIN]: Interrupted: {}", e.getMessage()); > } > } > > public static void main(String[] args) > { > try > { > Main main = new Main(); > main.start(); > } > catch (JoranException e) > { > System.out.println("Failed to load application: " + e.getMessage()); > } > } > } > ------------------------------- > Task.java > ------------------------------- > import java.util.Date; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > public class Task implements Runnable > { > private final Logger logger = LoggerFactory.getLogger(Task.class); > private final Logger logger_main = LoggerFactory.getLogger(Main.class); > private final String name; > private final long start; > > public Task(final String name) > { > this.name = name; > start = new Date().getTime(); > } > public void run() > { > logger.debug("[{}] {}", name, new Date().getTime() - start); > logger_main.debug("[MAIN] - [{}] {}", name, new Date().getTime() - start); > } > } -- 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: (LBCORE-47) JMS Appender Fails - Odd Interaction with Commons Logging
by Ceki Gulcu (JIRA) 15 Oct '08

15 Oct '08

[ http://jira.qos.ch/browse/LBCORE-47?page=com.atlassian.jira.plugin.system.i… ] Ceki Gulcu commented on LBCORE-47: ---------------------------------- Todd, Thank you for supplying a testbed. It made it easier to reproduce the problem. The problem can be described as follows: 1) In the static initializer of the LoggerFactory class, the result of StaticLoggerBinder.SINGLETON.getLoggerFactory() is assigned to the loggerFactory variable 2) the StaticLoggerBinder.SINGLETON.getLoggerFactory() call, instantiates a logback LoggerContext which proceeds with auto-initialization. 3) auto-initialization reads the config file which creates a .ActiveMQInitialContextFactory 4) this ActiveMQInitialContextFactory class performs logging via commons-logging. However, at this stage the loggerFactory variable is not yet assigned. Hence the error. There are several ways to solve this problem. A) assign loggerFactory to a nopFactory value just before calling StaticLoggerBinder.SINGLETON.getLoggerFactory() B) have LoggerFactory invoke auto-initialization as a second step after the loggerFactory variable is assigned. This would require the addition of a new method, say autoInitialize()w to the ILoggerFactory interface. C) Have logback perform auto-initialization in two steps. In the first step only non-re-entrant appenders are configured. Re-entrant appenders are left as a job to be performed by a different thread a later time. This is too complicated a solution to be further discussed. Approach A implies that a NOPLogger needs to be merged into slf4j-api. Approach B would work very well with logback. However, this bug is not logback specific, if log4j were the underlying logging system, then it would still occur. Given that log4j is not a native SLF4J implementation without knowledge of the ILoggerFactory.autoInitialize() method, approach B is not valid for log4j. I guess that just leaves A. > JMS Appender Fails - Odd Interaction with Commons Logging > --------------------------------------------------------- > > Key: LBCORE-47 > URL: http://jira.qos.ch/browse/LBCORE-47 > Project: logback-core > Issue Type: Bug > Components: Appender > Affects Versions: unspecified > Environment: Operating System: Windows > Platform: PC > Reporter: todd orr > Assignee: Ceki Gulcu > Priority: Blocker > Attachments: testbed.zip > > > I'm not sure exactly what's going on, but I've been able to determine that the JMS appender doesn't work under certain circumstances due to some interaction with commons logging. > Here is my maven POM: > <?xml version="1.0" encoding="UTF-8"?> > <project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/maven-v4_0_0.xsd"> > <modelVersion>4.0.0</modelVersion> > <groupId>foo.bar</groupId> > <artifactId>testbed</artifactId> > <name>Testbed</name> > <packaging>jar</packaging> > <version>0.1-SNAPSHOT</version> > <build> > <plugins> > <plugin> > <artifactId>maven-compiler-plugin</artifactId> > <configuration> > <source>1.5</source> > <target>1.5</target> > </configuration> > </plugin> > </plugins> > </build> > <dependencies> > <dependency> > <groupId>org.apache.activemq</groupId> > <artifactId>activemq-core</artifactId> > <version>5.0.0</version> > <exclusions> > <exclusion> > <groupId>commons-logging</groupId> > <artifactId>commons-logging</artifactId> > </exclusion> > <exclusion> > <groupId>commons-logging</groupId> > <artifactId>commons-logging-api</artifactId> > </exclusion> > </exclusions> > </dependency> > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>slf4j-api</artifactId> > <version>1.4.3</version> > </dependency> > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>jcl104-over-slf4j</artifactId> > <version>1.4.3</version> > </dependency> > <dependency> > <groupId>ch.qos.logback</groupId> > <artifactId>logback-core</artifactId> > <version>0.9.9</version> > </dependency> > <dependency> > <groupId>ch.qos.logback</groupId> > <artifactId>logback-classic</artifactId> > <version>0.9.9</version> > </dependency> > </dependencies> > </project> > Here is my logback config: > <configuration debug="true"> > <appender name="STDOUT" > class="ch.qos.logback.core.ConsoleAppender"> > <layout class="ch.qos.logback.classic.PatternLayout"> > <Pattern> > %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n > </Pattern> > </layout> > </appender> >  > <root> > <level value="TRACE" /> > <appender-ref ref="STDOUT" /> > </root> > </configuration> > Uncommenting the QUEUE appender results in the following stack trace: > Failed to instantiate [ch.qos.logback.classic.LoggerContext] > Reported exception: > java.lang.ExceptionInInitializerError > at org.apache.activemq.ActiveMQConnectionFactory.<init>(ActiveMQConnectionFactory.java:88) > at org.apache.activemq.ActiveMQConnectionFactory.<init>(ActiveMQConnectionFactory.java:121) > at org.apache.activemq.ActiveMQConnectionFactory.<init>(ActiveMQConnectionFactory.java:117) > at org.apache.activemq.jndi.ActiveMQInitialContextFactory.createConnectionFactory(ActiveMQInitialContextFactory.java:201) > at org.apache.activemq.jndi.ActiveMQInitialContextFactory.createConnectionFactory(ActiveMQInitialContextFactory.java:140) > at org.apache.activemq.jndi.ActiveMQInitialContextFactory.getInitialContext(ActiveMQInitialContextFactory.java:65) > at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:667) > at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:247) > at javax.naming.InitialContext.init(InitialContext.java:223) > at javax.naming.InitialContext.<init>(InitialContext.java:197) > at ch.qos.logback.core.net.JMSAppenderBase.buildJNDIContext(JMSAppenderBase.java:49) > at ch.qos.logback.classic.net.JMSQueueAppender.start(JMSQueueAppender.java:89) > at ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:89) > at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:310) > at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:173) > at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:154) > at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:48) > at ch.qos.logback.core.joran.spi.Interpreter.play(Interpreter.java:336) > at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:96) > at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:74) > at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:38) > at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:23) > at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:34) > at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:43) > at org.slf4j.impl.StaticLoggerBinder.initialize(StaticLoggerBinder.java:62) > at org.slf4j.impl.StaticLoggerBinder.<init>(StaticLoggerBinder.java:53) > at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:48) > at org.slf4j.LoggerFactory.<clinit>(LoggerFactory.java:60) > at foo.bar.testbed.LoggerTester.main(LoggerTester.java:9) > Caused by: java.lang.IllegalStateException: Logging factory implementation cannot be null. See also http://www.slf4j.org/codes.html#null_LF > at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:86) > at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:155) > at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:131) > at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:204) > at org.apache.activemq.ActiveMQPrefetchPolicy.<clinit>(ActiveMQPrefetchPolicy.java:30) > ... 29 more > Failed to instantiate logger [ch.qos.logback.classic.selector.ContextSelector] > Reported exception: > java.lang.IllegalStateException: contextSelector cannot be null. See also http://logback.qos.ch/codes.html#null_CS > at org.slf4j.impl.StaticLoggerBinder.getLoggerFactory(StaticLoggerBinder.java:98) > at org.slf4j.LoggerFactory.<clinit>(LoggerFactory.java:60) > at foo.bar.testbed.LoggerTester.main(LoggerTester.java:9) > Exception in thread "main" java.lang.IllegalStateException: Logging factory implementation cannot be null. See also http://www.slf4j.org/codes.html#null_LF > at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:101) > at foo.bar.testbed.LoggerTester.main(LoggerTester.java:9) > However, removing the SLF4J commons bridge and un-excluding the commons libs from activemq results in the correct behavior. At this point the commons logging is not running through SLF4J at this point. So this is not desirable. -- 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: (LBGENERAL-16) logback 0.9.8 keeps dropping and recreating connections
by Ceki Gulcu (JIRA) 15 Oct '08

15 Oct '08

[ http://jira.qos.ch/browse/LBGENERAL-16?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBGENERAL-16: ------------------------------------- Sorry for my previous comment. I had not seen the previous comments. Anyway, if you print the contents of status messages, then you should get a much better idea of what is going on. > logback 0.9.8 keeps dropping and recreating connections > ------------------------------------------------------- > > Key: LBGENERAL-16 > URL: http://jira.qos.ch/browse/LBGENERAL-16 > Project: logback-general > Issue Type: Bug > Components: build-structure > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Joern Huxhorn > Assignee: Logback dev list > Priority: Blocker > > I have a serious problem with logback 0.9.8 that forced me to downgrade to 0.9.7 again. > The socket-appender keeps dropping and recreating connections, missing log-events in the process. It does so at least once, i.e. creating a connection without writing a single event and then closing it again immeditaly. > I tried to reporduce the behaviour in a simple test program but didn't succeed. Everything is fine in a simple test. > In both of our "real" applications, however, this problem is definitly reproducible and just vanishes after a downgrade to 0.9.7. I suspect that the problem is connected to log4j-over-slf4j because that's one of the differences to my small test. > We have the following dependencies: > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>slf4j-api</artifactId> > <scope>compile</scope> > </dependency> > <dependency> > <groupId>commons-logging</groupId> > <artifactId>commons-logging</artifactId> > <scope>provided</scope> > </dependency> > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>jcl104-over-slf4j</artifactId> > <scope>runtime</scope> > </dependency> > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>log4j-over-slf4j</artifactId> > <scope>runtime</scope> > </dependency> > <dependency> > <groupId>log4j</groupId> > <artifactId>log4j</artifactId> > <scope>provided</scope> > </dependency> > <dependency> > <groupId>ch.qos.logback</groupId> > <artifactId>logback-core</artifactId> > <scope>compile</scope> > </dependency> > <dependency> > <groupId>ch.qos.logback</groupId> > <artifactId>logback-classic</artifactId> > <scope>compile</scope> > </dependency> > with slf4j 1.4.3 and logback 0.9.8 as version. > We use several third-party jars in our apps, e.g. spring, commons-stuff etc., so we have to map both commons-logging as well as log4j to logback. > This worked perfectly up to version 0.9.7 but doesn't work anymore! > I'm sorry about this rather obscure error report but I'm really quite clueless about the problem myself. I just checked the svn repos and the last socket appender change was done 4 month ago so that can't be responsible... > I'll try to investigate this some more but you might already know what's wrong since you know what changed between 0.9.7 and 0.9.8. > The problem exists on at least Windows and Solaris, btw. -- 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: (LBGENERAL-16) logback 0.9.8 keeps dropping and recreating connections
by Ceki Gulcu (JIRA) 15 Oct '08

15 Oct '08

[ http://jira.qos.ch/browse/LBGENERAL-16?page=com.atlassian.jira.plugin.syste… ] Ceki Gulcu commented on LBGENERAL-16: ------------------------------------- Joern, Is it possible that the client and server side use different logback versions? > logback 0.9.8 keeps dropping and recreating connections > ------------------------------------------------------- > > Key: LBGENERAL-16 > URL: http://jira.qos.ch/browse/LBGENERAL-16 > Project: logback-general > Issue Type: Bug > Components: build-structure > Affects Versions: unspecified > Environment: Operating System: All > Platform: All > Reporter: Joern Huxhorn > Assignee: Logback dev list > Priority: Blocker > > I have a serious problem with logback 0.9.8 that forced me to downgrade to 0.9.7 again. > The socket-appender keeps dropping and recreating connections, missing log-events in the process. It does so at least once, i.e. creating a connection without writing a single event and then closing it again immeditaly. > I tried to reporduce the behaviour in a simple test program but didn't succeed. Everything is fine in a simple test. > In both of our "real" applications, however, this problem is definitly reproducible and just vanishes after a downgrade to 0.9.7. I suspect that the problem is connected to log4j-over-slf4j because that's one of the differences to my small test. > We have the following dependencies: > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>slf4j-api</artifactId> > <scope>compile</scope> > </dependency> > <dependency> > <groupId>commons-logging</groupId> > <artifactId>commons-logging</artifactId> > <scope>provided</scope> > </dependency> > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>jcl104-over-slf4j</artifactId> > <scope>runtime</scope> > </dependency> > <dependency> > <groupId>org.slf4j</groupId> > <artifactId>log4j-over-slf4j</artifactId> > <scope>runtime</scope> > </dependency> > <dependency> > <groupId>log4j</groupId> > <artifactId>log4j</artifactId> > <scope>provided</scope> > </dependency> > <dependency> > <groupId>ch.qos.logback</groupId> > <artifactId>logback-core</artifactId> > <scope>compile</scope> > </dependency> > <dependency> > <groupId>ch.qos.logback</groupId> > <artifactId>logback-classic</artifactId> > <scope>compile</scope> > </dependency> > with slf4j 1.4.3 and logback 0.9.8 as version. > We use several third-party jars in our apps, e.g. spring, commons-stuff etc., so we have to map both commons-logging as well as log4j to logback. > This worked perfectly up to version 0.9.7 but doesn't work anymore! > I'm sorry about this rather obscure error report but I'm really quite clueless about the problem myself. I just checked the svn repos and the last socket appender change was done 4 month ago so that can't be responsible... > I'll try to investigate this some more but you might already know what's wrong since you know what changed between 0.9.7 and 0.9.8. > The problem exists on at least Windows and Solaris, btw. -- 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