You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rp...@apache.org on 2015/08/22 15:15:37 UTC
logging-log4j2 git commit: LOG4J2-1097 updated DatePatternConverter
to use FixedDateFormat
Repository: logging-log4j2
Updated Branches:
refs/heads/master d8935c8a8 -> c18acf171
LOG4J2-1097 updated DatePatternConverter to use FixedDateFormat
- added FixedFormatter helper inner class that wraps a FixedDateFormat
- simplified constructor code for creating a Formatter
- removed constants (moved to FixedDateFormat.FixedFormat enum)
- renamed CurrentTime helper inner class to CachedTime
- added method DatePatternConverter::format(long, StringBuilder)
- added unit tests
- also updated changes.xml to add an entry for LOG4J2-812
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/c18acf17
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/c18acf17
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/c18acf17
Branch: refs/heads/master
Commit: c18acf17119a0849b104d33beca19c0ed66832d7
Parents: d8935c8
Author: rpopma <rp...@apache.org>
Authored: Sat Aug 22 22:15:32 2015 +0900
Committer: rpopma <rp...@apache.org>
Committed: Sat Aug 22 22:15:32 2015 +0900
----------------------------------------------------------------------
.../core/pattern/DatePatternConverter.java | 191 +++++++------------
.../core/pattern/DatePatternConverterTest.java | 67 ++++++-
src/changes/changes.xml | 8 +
3 files changed, 140 insertions(+), 126 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/c18acf17/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/DatePatternConverter.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/DatePatternConverter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/DatePatternConverter.java
index 44fa843..b7c4cd6 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/DatePatternConverter.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/DatePatternConverter.java
@@ -17,12 +17,15 @@
package org.apache.logging.log4j.core.pattern;
import java.util.Date;
+import java.util.Objects;
import java.util.TimeZone;
import java.util.concurrent.atomic.AtomicReference;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.util.datetime.FastDateFormat;
+import org.apache.logging.log4j.core.util.datetime.FixedDateFormat;
+import org.apache.logging.log4j.core.util.datetime.FixedDateFormat.FixedFormat;
/**
* Converts and formats the event's date in a StringBuilder.
@@ -31,17 +34,17 @@ import org.apache.logging.log4j.core.util.datetime.FastDateFormat;
@ConverterKeys({ "d", "date" })
public final class DatePatternConverter extends LogEventPatternConverter implements ArrayPatternConverter {
- private final class CurrentTime {
+ private final class CachedTime {
public long timestampMillis;
public String formatted;
- public CurrentTime(final long timestampMillis) {
+ public CachedTime(final long timestampMillis) {
this.timestampMillis = timestampMillis;
this.formatted = formatter.format(this.timestampMillis);
}
}
- private final AtomicReference<CurrentTime> currentTime;
+ private final AtomicReference<CachedTime> cachedTime;
private abstract static class Formatter {
abstract String format(long timeMillis);
@@ -69,13 +72,30 @@ public final class DatePatternConverter extends LogEventPatternConverter impleme
}
}
+ private static final class FixedFormatter extends Formatter {
+ private final FixedDateFormat fixedDateFormat;
+
+ FixedFormatter(final FixedDateFormat fixedDateFormat) {
+ this.fixedDateFormat = fixedDateFormat;
+ }
+
+ @Override
+ String format(final long timeMillis) {
+ return fixedDateFormat.format(timeMillis);
+ }
+
+ @Override
+ public String toPattern() {
+ return fixedDateFormat.getFormat();
+ }
+ }
+
private static final class UnixFormatter extends Formatter {
@Override
String format(final long timeMillis) {
return Long.toString(timeMillis / 1000);
}
-
}
private static final class UnixMillisFormatter extends Formatter {
@@ -84,73 +104,9 @@ public final class DatePatternConverter extends LogEventPatternConverter impleme
String format(final long timeMillis) {
return Long.toString(timeMillis);
}
-
}
/**
- * ABSOLUTE string literal.
- */
- private static final String ABSOLUTE_FORMAT = "ABSOLUTE";
-
- /**
- * SimpleTimePattern for ABSOLUTE.
- */
- private static final String ABSOLUTE_TIME_PATTERN = "HH:mm:ss,SSS";
-
- /**
- * COMPACT string literal.
- */
- private static final String COMPACT_FORMAT = "COMPACT";
-
- /**
- * SimpleTimePattern for COMPACT.
- */
- private static final String COMPACT_PATTERN = "yyyyMMddHHmmssSSS";
-
- /**
- * DATE string literal.
- */
- private static final String DATE_AND_TIME_FORMAT = "DATE";
-
- /**
- * SimpleTimePattern for DATE.
- */
- private static final String DATE_AND_TIME_PATTERN = "dd MMM yyyy HH:mm:ss,SSS";
-
- /**
- * DEFAULT string literal.
- */
- private static final String DEFAULT_FORMAT = "DEFAULT";
-
- /**
- * SimpleTimePattern for DEFAULT.
- */
- // package private for unit tests
- static final String DEFAULT_PATTERN = "yyyy-MM-dd HH:mm:ss,SSS";
-
- /**
- * ISO8601_BASIC string literal.
- */
- private static final String ISO8601_BASIC_FORMAT = "ISO8601_BASIC";
-
- /**
- * SimpleTimePattern for ISO8601_BASIC.
- */
- private static final String ISO8601_BASIC_PATTERN = "yyyyMMdd'T'HHmmss,SSS";
-
- /**
- * ISO8601 string literal.
- */
- // package private for unit tests
- static final String ISO8601_FORMAT = "ISO8601";
-
- /**
- * SimpleTimePattern for ISO8601.
- */
- // package private for unit tests
- static final String ISO8601_PATTERN = "yyyy-MM-dd'T'HH:mm:ss,SSS";
-
- /**
* UNIX formatter in seconds (standard).
*/
private static final String UNIX_FORMAT = "UNIX";
@@ -182,56 +138,49 @@ public final class DatePatternConverter extends LogEventPatternConverter impleme
private DatePatternConverter(final String[] options) {
super("Date", "date");
- // null patternOption is OK.
- final String patternOption = options != null && options.length > 0 ? options[0] : null;
-
- String pattern = null;
- Formatter tempFormatter = null;
-
- if (patternOption == null || patternOption.equalsIgnoreCase(DEFAULT_FORMAT)) {
- pattern = DEFAULT_PATTERN;
- } else if (patternOption.equalsIgnoreCase(ISO8601_FORMAT)) {
- pattern = ISO8601_PATTERN;
- } else if (patternOption.equalsIgnoreCase(ISO8601_BASIC_FORMAT)) {
- pattern = ISO8601_BASIC_PATTERN;
- } else if (patternOption.equalsIgnoreCase(ABSOLUTE_FORMAT)) {
- pattern = ABSOLUTE_TIME_PATTERN;
- } else if (patternOption.equalsIgnoreCase(DATE_AND_TIME_FORMAT)) {
- pattern = DATE_AND_TIME_PATTERN;
- } else if (patternOption.equalsIgnoreCase(COMPACT_FORMAT)) {
- pattern = COMPACT_PATTERN;
- } else if (patternOption.equalsIgnoreCase(UNIX_FORMAT)) {
- tempFormatter = new UnixFormatter();
- } else if (patternOption.equalsIgnoreCase(UNIX_MILLIS_FORMAT)) {
- tempFormatter = new UnixMillisFormatter();
+ final FixedDateFormat fixedDateFormat = FixedDateFormat.createIfSupported(options);
+ if (fixedDateFormat != null) {
+ formatter = createFormatter(fixedDateFormat);
} else {
- pattern = patternOption;
+ formatter = createFormatter(options);
}
+ cachedTime = new AtomicReference<>(new CachedTime(System.currentTimeMillis()));
+ }
- if (pattern != null) {
- FastDateFormat tempFormat;
-
- TimeZone tz = null;
-
- // if the option list contains a TZ option, then set it.
- if (options != null && options.length > 1) {
- tz = TimeZone.getTimeZone(options[1]);
- }
+ private static Formatter createFormatter(final FixedDateFormat fixedDateFormat) {
+ return new FixedFormatter(fixedDateFormat);
+ }
- try {
- tempFormat = FastDateFormat.getInstance(pattern, tz);
- } catch (final IllegalArgumentException e) {
- LOGGER.warn("Could not instantiate FastDateFormat with pattern " + patternOption, e);
+ private static Formatter createFormatter(final String[] options) {
+ // if we get here, options is a non-null array with at least one element (first of which non-null)
+ Objects.requireNonNull(options);
+ if (options.length == 0) {
+ throw new IllegalArgumentException("options array must have at least one element");
+ }
+ Objects.requireNonNull(options[0]);
+ final String patternOption = options[0];
+ if (UNIX_FORMAT.equals(patternOption)) {
+ return new UnixFormatter();
+ }
+ if (UNIX_MILLIS_FORMAT.equals(patternOption)) {
+ return new UnixMillisFormatter();
+ }
- // default to the DEFAULT format
- tempFormat = FastDateFormat.getInstance(DEFAULT_PATTERN);
- }
+ // if the option list contains a TZ option, then set it.
+ TimeZone tz = null;
+ if (options != null && options.length > 1) {
+ tz = TimeZone.getTimeZone(options[1]);
+ }
+ try {
+ final FastDateFormat tempFormat = FastDateFormat.getInstance(patternOption, tz);
+ return new PatternFormatter(tempFormat);
+ } catch (final IllegalArgumentException e) {
+ LOGGER.warn("Could not instantiate FastDateFormat with pattern " + patternOption, e);
- tempFormatter = new PatternFormatter(tempFormat);
+ // default to the DEFAULT format
+ return createFormatter(FixedDateFormat.create(FixedFormat.DEFAULT));
}
- formatter = tempFormatter;
- currentTime = new AtomicReference<>(new CurrentTime(System.currentTimeMillis()));
}
/**
@@ -243,7 +192,7 @@ public final class DatePatternConverter extends LogEventPatternConverter impleme
* buffer to which formatted date is appended.
*/
public void format(final Date date, final StringBuilder toAppendTo) {
- toAppendTo.append(formatter.format(date.getTime()));
+ format(date.getTime(), toAppendTo);
}
/**
@@ -251,18 +200,20 @@ public final class DatePatternConverter extends LogEventPatternConverter impleme
*/
@Override
public void format(final LogEvent event, final StringBuilder output) {
- final long timestampMillis = event.getTimeMillis();
- CurrentTime current = currentTime.get();
- if (timestampMillis != current.timestampMillis) {
- final CurrentTime newTime = new CurrentTime(timestampMillis);
- if (currentTime.compareAndSet(current, newTime)) {
- current = newTime;
+ format(event.getTimeMillis(), output);
+ }
+
+ public void format(final long timestampMillis, final StringBuilder output) {
+ CachedTime cached = cachedTime.get();
+ if (timestampMillis != cached.timestampMillis) {
+ final CachedTime newTime = new CachedTime(timestampMillis);
+ if (cachedTime.compareAndSet(cached, newTime)) {
+ cached = newTime;
} else {
- current = currentTime.get();
+ cached = cachedTime.get();
}
}
-
- output.append(current.formatted);
+ output.append(cached.formatted);
}
/**
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/c18acf17/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/DatePatternConverterTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/DatePatternConverterTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/DatePatternConverterTest.java
index 2e75928..2981a68 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/DatePatternConverterTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/pattern/DatePatternConverterTest.java
@@ -21,13 +21,24 @@ import java.util.Date;
import org.apache.logging.log4j.core.AbstractLogEvent;
import org.apache.logging.log4j.core.LogEvent;
+import org.apache.logging.log4j.core.util.datetime.FixedDateFormat;
import org.junit.Test;
import static org.junit.Assert.*;
public class DatePatternConverterTest {
- private static final String[] ISO8601_FORMAT = { DatePatternConverter.ISO8601_FORMAT };
+ /**
+ * SimpleTimePattern for DEFAULT.
+ */
+ private static final String DEFAULT_PATTERN = FixedDateFormat.FixedFormat.DEFAULT.getPattern();
+
+ /**
+ * ISO8601 string literal.
+ */
+ private static final String ISO8601_FORMAT = FixedDateFormat.FixedFormat.ISO8601.name();
+
+ private static final String[] ISO8601_FORMAT_OPTIONS = { ISO8601_FORMAT };
@Test
public void testNewInstanceAllowsNullParameter() {
@@ -48,7 +59,7 @@ public class DatePatternConverterTest {
@Test
public void testFormatLogEventStringBuilderIso8601() {
final LogEvent event = new MyLogEvent();
- final DatePatternConverter converter = DatePatternConverter.newInstance(ISO8601_FORMAT);
+ final DatePatternConverter converter = DatePatternConverter.newInstance(ISO8601_FORMAT_OPTIONS);
final StringBuilder sb = new StringBuilder();
converter.format(event, sb);
@@ -90,7 +101,7 @@ public class DatePatternConverterTest {
@Test
public void testFormatDateStringBuilderIso8601() {
- final DatePatternConverter converter = DatePatternConverter.newInstance(ISO8601_FORMAT);
+ final DatePatternConverter converter = DatePatternConverter.newInstance(ISO8601_FORMAT_OPTIONS);
final StringBuilder sb = new StringBuilder();
converter.format(date(2001, 1, 1), sb);
@@ -99,6 +110,17 @@ public class DatePatternConverterTest {
}
@Test
+ public void testFormatDateStringBuilderOriginalPattern() {
+ final String[] pattern = { "yyyy/MM/dd HH-mm-ss.SSS" };
+ final DatePatternConverter converter = DatePatternConverter.newInstance(pattern);
+ final StringBuilder sb = new StringBuilder();
+ converter.format(date(2001, 1, 1), sb);
+
+ final String expected = "2001/02/01 14-15-16.123";
+ assertEquals(expected, sb.toString());
+ }
+
+ @Test
public void testFormatStringBuilderObjectArrayDefaultPattern() {
final DatePatternConverter converter = DatePatternConverter.newInstance(null);
final StringBuilder sb = new StringBuilder();
@@ -110,7 +132,7 @@ public class DatePatternConverterTest {
@Test
public void testFormatStringBuilderObjectArrayIso8601() {
- final DatePatternConverter converter = DatePatternConverter.newInstance(ISO8601_FORMAT);
+ final DatePatternConverter converter = DatePatternConverter.newInstance(ISO8601_FORMAT_OPTIONS);
final StringBuilder sb = new StringBuilder();
converter.format(sb, date(2001, 1, 1), date(2002, 2, 2), date(2003, 3, 3));
@@ -126,8 +148,41 @@ public class DatePatternConverterTest {
}
@Test
- public void testGetPatternReturnsCorrectDefault() {
- assertEquals(DatePatternConverter.DEFAULT_PATTERN, DatePatternConverter.newInstance(null).getPattern());
+ public void testGetPatternReturnsDefaultForNullOptions() {
+ assertEquals(DEFAULT_PATTERN, DatePatternConverter.newInstance(null).getPattern());
+ }
+
+ @Test
+ public void testGetPatternReturnsDefaultForEmptyOptionsArray() {
+ assertEquals(DEFAULT_PATTERN, DatePatternConverter.newInstance(new String[0]).getPattern());
+ }
+
+ @Test
+ public void testGetPatternReturnsDefaultForSingleNullElementOptionsArray() {
+ assertEquals(DEFAULT_PATTERN, DatePatternConverter.newInstance(new String[1]).getPattern());
+ }
+
+ @Test
+ public void testGetPatternReturnsDefaultForTwoNullElementsOptionsArray() {
+ assertEquals(DEFAULT_PATTERN, DatePatternConverter.newInstance(new String[2]).getPattern());
+ }
+
+ @Test
+ public void testGetPatternReturnsDefaultForInvalidPattern() {
+ final String[] invalid = { "ABC I am not a valid date pattern" };
+ assertEquals(DEFAULT_PATTERN, DatePatternConverter.newInstance(invalid).getPattern());
+ }
+
+ @Test
+ public void testGetPatternReturnsNullForUnix() {
+ final String[] options = { "UNIX" };
+ assertNull(DatePatternConverter.newInstance(options).getPattern());
+ }
+
+ @Test
+ public void testGetPatternReturnsNullForUnixMillis() {
+ final String[] options = { "UNIX_MILLIS" };
+ assertNull(DatePatternConverter.newInstance(options).getPattern());
}
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/c18acf17/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index a92f0c1..9bafa66 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -31,6 +31,14 @@
Added support for Java 8 lambda expressions to lazily construct a log message only if
the requested log level is enabled.
</action>
+ <action issue="LOG4J2-812" dev="rgoers" type="update">
+ PatternLayout timestamp formatting performance improvement: replaced synchronized SimpleDateFormat with
+ Apache Commons FastDateFormat. This and better caching resulted in a ~3-30X faster timestamp formatting.
+ </action>
+ <action issue="LOG4J2-1097" dev="rpopma" type="update">
+ PatternLayout timestamp formatting performance improvement: predefined date formats (and variants using
+ a period '.' millisecond separator instead of ',') are now formatted ~2-10X faster than other date formats.
+ </action>
<action issue="LOG4J2-1096" dev="rpopma" type="update">
Improved performance of ParameterizedMessage::getFormattedMessage by ~2X.
</action>