[logback-dev] 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
noreply.ceki at qos.ch
noreply.ceki at qos.ch
Mon Jun 29 17:43:52 CEST 2009
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.
*
- * <p> The <code>immediateFlush</code> variable is set to <code>true</code>
- * by default.
+ * <p>
+ * 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. <p> The
- * <code>encoding</code> variable is set to <code>null</null> by default
+ * The encoding to use when opening an InputStream.
+ * <p>
+ * 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 <b>ImmediateFlush</b> 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. <p> 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.
+ * <p>
+ * 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.
*
- * <p> Stopped appenders cannot be reused.
+ * <p>
+ * 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 @@
}
/**
- * <p> 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.
+ * <p>
+ * 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. <p> Most subclasses of
- * <code>WriterAppender</code> will need to override this method.
+ * Actual writing occurs here.
+ * <p>
+ * 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));
}
}
-
}
More information about the logback-dev
mailing list