- logback-dev - mailman3.qos.ch

svn commit: r2311 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135
by noreply.ceki＠qos.ch 29 Jun '09

29 Jun '09

Author: ceki Date: Mon Jun 29 17:52:09 2009 New Revision: 2311 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Log: throughput results after revision 2310 is applied show noticeable degradation in throughput of 10 to 20% (on windows) Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Mon Jun 29 17:52:09 2009 @@ -14,7 +14,7 @@ */ public class LoggingToFileThrouhput { - static int THREAD_COUNT = 1; + static int THREAD_COUNT = 10; static long OVERALL_DURATION_IN_MILLIS = 5000; public static void main(String args[]) throws InterruptedException { @@ -73,6 +73,11 @@ // Threads 10: total of 309402 operations, or 61 operations per millisecond // Threads 1: total of 485077 operations, or 97 operations per millisecond +// After revision 2310 + +// Threads 1: total of 462465 operations, or 92 operations per millisecond +//Threads 10: total of 243362 operations, or 48 operations per millisecond + // java.runtime.version = 1.6.0_11-b03 // java.vendor = Sun Microsystems Inc. // os.name = Linux

1 0

svn commit: r2310 - in logback/trunk: logback-classic/src/main/java/ch/qos/logback/classic/pattern logback-classic/src/test/java/ch/qos/logback/classic/spi logback-core/src/main/java/ch/qos/logback/core
by noreply.ceki＠qos.ch 29 Jun '09

29 Jun '09

Author: ceki Date: Mon Jun 29 17:43:52 2009 New Revision: 2310 Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/CallerDataConverter.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/DateConverter.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/MDCConverter.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/RelativeTimeConverter.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/SyslogStartConverter.java logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/TargetLengthBasedClassNameAbbreviator.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/PubLoggingEventVO.java logback/trunk/logback-core/src/main/java/ch/qos/logback/core/UnsynchronizedAppenderBase.java logback/trunk/logback-core/src/main/java/ch/qos/logback/core/WriterAppender.java Log: Diminish contention in appender doAppender. Relates to LBCLASSIC-135 Instead of the doAppend method being synchronized, WriterAppender now uses UnsynchronizedAppenderBase as its super class. Consequently, various converters can no longer assume that they are invoked from within a synchronized block. Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/CallerDataConverter.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/CallerDataConverter.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/CallerDataConverter.java Mon Jun 29 17:43:52 2009 @@ -65,7 +65,6 @@ } } } - } private void addEvaluator(EventEvaluator<ILoggingEvent> ee) { @@ -76,7 +75,7 @@ } public String convert(ILoggingEvent le) { - StringBuffer buf = new StringBuffer(); + StringBuilder buf = new StringBuilder(); if (evaluatorList != null) { boolean printCallerData = false; Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/DateConverter.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/DateConverter.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/DateConverter.java Mon Jun 29 17:43:52 2009 @@ -17,56 +17,58 @@ import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.CoreConstants; - public class DateConverter extends ClassicConverter { - + long lastTimestamp = -1; - String timesmapStr = null; + String timestampStrCache = null; SimpleDateFormat simpleFormat = null; - + public void start() { - + String datePattern = getFirstOption(); - if(datePattern == null) { + if (datePattern == null) { datePattern = CoreConstants.ISO8601_PATTERN; } - + if (datePattern.equals(CoreConstants.ISO8601_STR)) { datePattern = CoreConstants.ISO8601_PATTERN; - } - + } + try { simpleFormat = new SimpleDateFormat(datePattern); - //maximumCacheValidity = CachedDateFormat.getMaximumCacheValidity(pattern); + // maximumCacheValidity = + // CachedDateFormat.getMaximumCacheValidity(pattern); } catch (IllegalArgumentException e) { - addWarn("Could not instantiate SimpleDateFormat with pattern " + datePattern, e); + addWarn("Could not instantiate SimpleDateFormat with pattern " + + datePattern, e); // default to the ISO8601 format simpleFormat = new SimpleDateFormat(CoreConstants.ISO8601_PATTERN); } - + List optionList = getOptionList(); - + // if the option list contains a TZ option, then set it. if (optionList != null && optionList.size() > 1) { TimeZone tz = TimeZone.getTimeZone((String) optionList.get(1)); simpleFormat.setTimeZone(tz); } } - + public String convert(ILoggingEvent le) { long timestamp = le.getTimeStamp(); - - // if called multiple times within the same millisecond - // return old value - if(timestamp == lastTimestamp) { - return timesmapStr; - } else { - lastTimestamp = timestamp; - // SimpleDateFormat is not thread safe. However, since - // the AppenderBase.doAppend is synchronized, we are should be - // OK. See also http://jira.qos.ch/browse/LBCLASSIC-36 - timesmapStr = simpleFormat.format(new Date(timestamp)); - return timesmapStr; + + synchronized (this) { + // if called multiple times within the same millisecond + // return cache value + if (timestamp == lastTimestamp) { + return timestampStrCache; + } else { + lastTimestamp = timestamp; + // SimpleDateFormat is not thread safe. + // See also http://jira.qos.ch/browse/LBCLASSIC-36 + timestampStrCache = simpleFormat.format(new Date(timestamp)); + return timestampStrCache; + } } } } Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/MDCConverter.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/MDCConverter.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/MDCConverter.java Mon Jun 29 17:43:52 2009 @@ -37,7 +37,7 @@ if (key == null) { // if no key is specified, return all the // values present in the MDC, separated with a single space. - StringBuffer buf = new StringBuffer(); + StringBuilder buf = new StringBuilder(); Set<String> keys = mdcPropertyMap.keySet(); Iterator it = keys.iterator(); String tmpKey; Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/RelativeTimeConverter.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/RelativeTimeConverter.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/RelativeTimeConverter.java Mon Jun 29 17:43:52 2009 @@ -14,19 +14,18 @@ public class RelativeTimeConverter extends ClassicConverter { long lastTimestamp = -1; - String timesmapStr = null; - + String timesmapCache = null; + public String convert(ILoggingEvent event) { - long timestamp = event.getTimeStamp(); - - // if called multiple times within the same millisecond - // return old value - if(timestamp == lastTimestamp) { - return timesmapStr; - } else { - lastTimestamp = timestamp; - timesmapStr = Long.toString(timestamp - event.getLoggerContextVO().getBirthTime()); - return timesmapStr; + long now = event.getTimeStamp(); + + synchronized (this) { + // update timesmapStrCache only if now != lastTimestamp + if (now != lastTimestamp) { + lastTimestamp = now; + timesmapCache = Long.toString(now - event.getLoggerContextVO().getBirthTime()); + } + return timesmapCache; } } } Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/SyslogStartConverter.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/SyslogStartConverter.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/SyslogStartConverter.java Mon Jun 29 17:43:52 2009 @@ -61,7 +61,7 @@ sb.append("<"); sb.append(pri); sb.append(">"); - fillInTimestamp(sb, event.getTimeStamp()); + sb.append(computeTimeStampString(event.getTimeStamp())); sb.append(' '); sb.append(localHostName); sb.append(' '); @@ -85,13 +85,13 @@ } } - void fillInTimestamp(StringBuilder sb, long timestamp) { - // if called multiple times within the same millisecond - // use last value - if (timestamp != lastTimestamp) { - lastTimestamp = timestamp; - timesmapStr = simpleFormat.format(new Date(timestamp)); + String computeTimeStampString(long now) { + synchronized (this) { + if (now != lastTimestamp) { + lastTimestamp = now; + timesmapStr = simpleFormat.format(new Date(now)); + } + return timesmapStr; } - sb.append(timesmapStr); - } + } } Modified: logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/TargetLengthBasedClassNameAbbreviator.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/TargetLengthBasedClassNameAbbreviator.java (original) +++ logback/trunk/logback-classic/src/main/java/ch/qos/logback/classic/pattern/TargetLengthBasedClassNameAbbreviator.java Mon Jun 29 17:43:52 2009 @@ -14,17 +14,14 @@ public class TargetLengthBasedClassNameAbbreviator implements Abbreviator { - static private final int BUF_LIMIT = 256; - final int targetLength; - StringBuffer buf; public TargetLengthBasedClassNameAbbreviator(int targetLength) { - this.targetLength = targetLength; - buf = new StringBuffer(targetLength); + this.targetLength = targetLength; } public String abbreviate(String fqClassName) { + StringBuilder buf = new StringBuilder(targetLength); if (fqClassName == null) { throw new IllegalArgumentException("Class name may not be null"); } @@ -34,11 +31,6 @@ return fqClassName; } - if (buf.capacity() > BUF_LIMIT) { - buf = new StringBuffer(targetLength); - } - buf.setLength(0); - int[] dotIndexesArray = new int[ClassicConstants.MAX_DOTS]; // a.b.c contains 2 dots but 2+1 parts. // see also http://jira.qos.ch/browse/LBCLASSIC-110 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/PubLoggingEventVO.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/PubLoggingEventVO.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/spi/PubLoggingEventVO.java Mon Jun 29 17:43:52 2009 @@ -21,7 +21,7 @@ import ch.qos.logback.classic.Level; /** - * A read/write and serializable implementation of {@link ILoggingEvent}. + * A read/write and serializable implementation of {@link ILoggingEvent}. * * @author Ceki Gülcü Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/UnsynchronizedAppenderBase.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/UnsynchronizedAppenderBase.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/UnsynchronizedAppenderBase.java Mon Jun 29 17:43:52 2009 @@ -58,7 +58,7 @@ private int statusRepeatCount = 0; private int exceptionCount = 0; - static final int ALLOWED_REPEATS = 5; + static final int ALLOWED_REPEATS = 3; public void doAppend(E eventObject) { // WARNING: The guard check MUST be the first statement in the 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 Mon Jun 29 17:43:52 2009 @@ -26,7 +26,7 @@ * * @author Ceki Gülcü */ -public class WriterAppender<E> extends AppenderBase<E> { +public class WriterAppender<E> extends UnsynchronizedAppenderBase<E> { /** * Immediate flush means that the underlying writer or output stream will be @@ -36,14 +36,16 @@ * is a good chance that the last few logs events are not actually written to * persistent media if and when the application crashes. * - * The <code>immediateFlush</code> variable is set to <code>true</code> - * by default. + * + * The <code>immediateFlush</code> variable is set to <code>true</code> by + * default. */ private boolean immediateFlush = true; /** - * The encoding to use when opening an InputStream. The - * <code>encoding</code> variable is set to <code>null</null> by default + * The encoding to use when opening an InputStream. + * + * The <code>encoding</code> variable is set to <code>null</null> by default * which results in the use of the system's default encoding. */ private String encoding; @@ -53,7 +55,6 @@ */ private Writer writer; - /** * The default constructor does nothing. */ @@ -64,12 +65,14 @@ * If the ImmediateFlush option is set to <code>true</code>, the * appender will flush at the end of each write. This is the default behavior. * If the option is set to <code>false</code>, then the underlying stream - * can defer writing to physical medium to a later time. Avoiding the - * flush operation at the end of each append results in a performance gain of - * 10 to 20 percent. However, there is safety tradeoff involved in skipping - * flushing. Indeed, when flushing is skipped, then it is likely that the last - * few log events will not be recorded on disk when the application exits. - * This is a high price to pay even for a 20% performance gain. + * can defer writing to physical medium to a later time. + * + * Avoiding the flush operation at the end of each append results in a + * performance gain of 10 to 20 percent. However, there is safety tradeoff + * involved in skipping flushing. Indeed, when flushing is skipped, then it is + * likely that the last few log events will not be recorded on disk when the + * application exits. This is a high price to pay even for a 20% performance + * gain. */ public void setImmediateFlush(boolean value) { immediateFlush = value; @@ -118,7 +121,8 @@ * Stop this appender instance. The underlying stream or writer is also * closed. * - * Stopped appenders cannot be reused. + * + * Stopped appenders cannot be reused. */ public synchronized void stop() { closeWriter(); @@ -177,7 +181,6 @@ encoding = value; } - void writeHeader() { if (layout != null && (this.writer != null)) { try { @@ -224,12 +227,13 @@ } /** - * Sets the Writer where the log output will go. The specified Writer must - * be opened by the user and be writable. The <code>java.io.Writer</code> - * will be closed when the appender instance is closed. + * + * Sets the Writer where the log output will go. The specified Writer must be + * opened by the user and be writable. The <code>java.io.Writer</code> will + * 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 @@ -247,8 +251,10 @@ } /** - * Actual writing occurs here. Most subclasses of - * <code>WriterAppender</code> will need to override this method. + * Actual writing occurs here. + * + * Most subclasses of <code>WriterAppender</code> will need to override this + * method. * * @since 0.9.0 */ @@ -258,7 +264,10 @@ } try { - writerWrite(this.layout.doLayout(event), this.immediateFlush); + String output = this.layout.doLayout(event); + synchronized (this) { + writerWrite(output, this.immediateFlush); + } } catch (IOException ioe) { // as soon as an exception occurs, move to non-started state // and add a single ErrorStatus to the SM. @@ -266,5 +275,4 @@ addStatus(new ErrorStatus("IO failure in appender", this, ioe)); } } - }

1 0

[JIRA] Created: (LBSITE-28) Logback-Classic as Logging-Backend w/ Maven Jetty Plugin
by Sebastian Davids (JIRA) 28 Jun '09

28 Jun '09

Logback-Classic as Logging-Backend w/ Maven Jetty Plugin -------------------------------------------------------- Key: LBSITE-28 URL: http://jira.qos.ch/browse/LBSITE-28 Project: logback-site Issue Type: Improvement Reporter: Sebastian Davids Assignee: Logback dev list http://docs.codehaus.org/display/JETTY/Maven+Jetty+Plugin http://logback.qos.ch/faq.html#setup_jetty You should add the following or something similar to the FAQ: pom.xml: <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"> ... <build> ... <plugins> <plugin> <groupId>org.mortbay.jetty</groupId> <artifactId>maven-jetty-plugin</artifactId> <configuration> ... <systemProperties> <systemProperty> <name>logback.configurationFile</name> <value>./src/etc/logback.xml</value> </systemProperty> </systemProperties> </configuration> <dependencies> <dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-classic</artifactId> <version>${lb.version}</version> </dependency> ... </dependencies> </plugin> </plugins> </build> <properties> <lb.version>0.9.15</lb.version> </properties> </project> If one just adds the dependency on logback-classic the BasicConfigurator will be used for Jetty, resulting in a lot of debug statements. The important part is the systemProperty. You might want to update the example at http://svn.qos.ch/repos/logback-demo/tags/STABLE also. -- 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

DSL for configuring logback
by Ceki Gulcu 28 Jun '09

28 Jun '09

Hello all, At the Jazoon 2009 conference, I attended a talk by Hans Dockter on Gradle, a build framework based on Groovy. The ability to mix language features within the build file itself was quite convincing so as to switch on a dim light inside my head. I think it would be worthwhile to explore the creation of a DSL for configuring logback. Anyone interested to work on this? I have already asked Jason Dillon and he has not answered yet. Cheers, -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

4 10

svn commit: r2309 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135
by noreply.ceki＠qos.ch 26 Jun '09

26 Jun '09

Author: ceki Date: Fri Jun 26 23:28:19 2009 New Revision: 2309 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Log: single thereaded results with IBM's JDK Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Fri Jun 26 23:28:19 2009 @@ -86,4 +86,6 @@ // java.version = 1.6.0 // os.name = Linux // os.version = 2.6.25-gentoo-r6 -// File: total of 142989 operations, or 28 operations per millisecond +// Threads 10 total of 142989 operations, or 28 operations per millisecond +// Threads 1: total of 280381 operations, or 56 operations per millisecond +

1 0

svn commit: r2308 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135
by noreply.ceki＠qos.ch 26 Jun '09

26 Jun '09

Author: ceki Date: Fri Jun 26 23:26:02 2009 New Revision: 2308 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Log: single threaded result on linux Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Fri Jun 26 23:26:02 2009 @@ -73,12 +73,14 @@ // Threads 10: total of 309402 operations, or 61 operations per millisecond // Threads 1: total of 485077 operations, or 97 operations per millisecond -// java.runtime.version = 1.6.0_11-b03 -// java.vendor = Sun Microsystems Inc. -// os.name = Linux -// os.version = 2.6.25-gentoo-r6 -// File: total of 287943 operations, or 57 operations per millisecond -// +// java.runtime.version = 1.6.0_11-b03 +// java.vendor = Sun Microsystems Inc. +// os.name = Linux +// os.version = 2.6.25-gentoo-r6 +// Threads 10: total of 287943 operations, or 57 operations per millisecond +// Threads 1: total of 356355 operations, or 71 operations per millisecond + + // java.runtime.version = jvmxa6460-20081105_25433 // java.vendor = IBM Corporation // java.version = 1.6.0

1 0

svn commit: r2307 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135
by noreply.ceki＠qos.ch 26 Jun '09

26 Jun '09

Author: ceki Date: Fri Jun 26 23:23:13 2009 New Revision: 2307 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Log: - single threaded results Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Fri Jun 26 23:23:13 2009 @@ -14,7 +14,7 @@ */ public class LoggingToFileThrouhput { - static int THREAD_COUNT = 10; + static int THREAD_COUNT = 1; static long OVERALL_DURATION_IN_MILLIS = 5000; public static void main(String args[]) throws InterruptedException { @@ -70,8 +70,9 @@ // java.vendor = Sun Microsystems Inc. // os.name = Windows XP // -// File: total of 309402 operations, or 61 operations per millisecond -// +// Threads 10: total of 309402 operations, or 61 operations per millisecond +// Threads 1: total of 485077 operations, or 97 operations per millisecond + // java.runtime.version = 1.6.0_11-b03 // java.vendor = Sun Microsystems Inc. // os.name = Linux

1 0

svn commit: r2306 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135
by noreply.ceki＠qos.ch 26 Jun '09

26 Jun '09

Author: ceki Date: Fri Jun 26 23:18:43 2009 New Revision: 2306 Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Log: results on Linux, with both Sun's and IBM's JDKs Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Fri Jun 26 23:18:43 2009 @@ -62,10 +62,25 @@ } } -//=== lbclassic135 LoggingToFileThrouhput === 10 Threads -//java.runtime.version = 1.6.0_05-b13 -//java.vendor = Sun Microsystems Inc. -//java.version = 1.6.0_05 -//os.name = Windows XP +//=== lbclassic135 LoggingToFileThrouhput === +// ******** 10 Threads ***** +// synchronized doAppend() method +// +// java.runtime.version = 1.6.0_05-b13 +// java.vendor = Sun Microsystems Inc. +// os.name = Windows XP // // File: total of 309402 operations, or 61 operations per millisecond +// +// java.runtime.version = 1.6.0_11-b03 +// java.vendor = Sun Microsystems Inc. +// os.name = Linux +// os.version = 2.6.25-gentoo-r6 +// File: total of 287943 operations, or 57 operations per millisecond +// +// 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 +// File: total of 142989 operations, or 28 operations per millisecond

1 0

svn commit: r2305 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135
by noreply.ceki＠qos.ch 26 Jun '09

26 Jun '09

Author: ceki Date: Fri Jun 26 23:03:48 2009 New Revision: 2305 Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Log: test throughput of FileAppender before the syncronized block is made smaller Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingRunnable.java Fri Jun 26 23:03:48 2009 @@ -0,0 +1,21 @@ +package ch.qos.logback.classic.issue.lbclassic135; + +import ch.qos.logback.classic.Logger; +import ch.qos.logback.core.contention.RunnableWithCounterAndDone; + +public class LoggingRunnable extends RunnableWithCounterAndDone { + + Logger logger; + + LoggingRunnable(Logger logger) { + this.logger = logger; + } + + public void run() { + while(!isDone()) { + logger.info("hello world ABCDEFGHI"); + counter++; + } + } + +} Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/LoggingToFileThrouhput.java Fri Jun 26 23:03:48 2009 @@ -0,0 +1,71 @@ +package ch.qos.logback.classic.issue.lbclassic135; + +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.PatternLayout; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.FileAppender; +import ch.qos.logback.core.contention.ThreadedThroughputCalculator; + +/** + * Short sample code testing the throughput of a fair lock. + * + * @author Ceki Gulcu + */ +public class LoggingToFileThrouhput { + + static int THREAD_COUNT = 10; + static long OVERALL_DURATION_IN_MILLIS = 5000; + + public static void main(String args[]) throws InterruptedException { + + ThreadedThroughputCalculator tp = new ThreadedThroughputCalculator( + OVERALL_DURATION_IN_MILLIS); + tp.printEnvironmentInfo("lbclassic135 LoggingToFileThrouhput"); + + LoggerContext lc = new LoggerContext(); + Logger logger = buildLoggerContext(lc); + + for (int i = 0; i < 2; i++) { + tp.execute(buildArray(logger)); + } + + tp.execute(buildArray(logger)); + tp.printThroughput("File: "); + lc.stop(); + } + + static Logger buildLoggerContext(LoggerContext lc) { + Logger root = lc.getLogger(LoggerContext.ROOT_NAME); + + PatternLayout patternLayout = new PatternLayout(); + patternLayout.setContext(lc); + patternLayout.setPattern("%d %l [%t] - %msg%n"); + patternLayout.start(); + FileAppender<ILoggingEvent> fileAppender = new FileAppender<ILoggingEvent>(); + fileAppender.setContext(lc); + fileAppender.setFile("target/lbclassic135.log"); + fileAppender.setLayout(patternLayout); + fileAppender.setAppend(false); + fileAppender.start(); + root.addAppender(fileAppender); + return lc.getLogger(LoggingToFileThrouhput.class); + } + + static LoggingRunnable[] buildArray(Logger logger) { + + LoggingRunnable[] array = new LoggingRunnable[THREAD_COUNT]; + for (int i = 0; i < THREAD_COUNT; i++) { + array[i] = new LoggingRunnable(logger); + } + return array; + } +} + +//=== lbclassic135 LoggingToFileThrouhput === 10 Threads +//java.runtime.version = 1.6.0_05-b13 +//java.vendor = Sun Microsystems Inc. +//java.version = 1.6.0_05 +//os.name = Windows XP +// +// File: total of 309402 operations, or 61 operations per millisecond

1 0

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

26 Jun '09

Author: ceki Date: Fri Jun 26 22:34:24 2009 New Revision: 2304 Removed: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/ Log: lbclassic-133 was renamed as lbclassic-139

1 0