LOG4J2-1883 bugfixes and small enhancements
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/d41ecf43 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/d41ecf43 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/d41ecf43 Branch: refs/heads/master Commit: d41ecf4381756a684925c565061ce647e200a0fc Parents: bdedd4f Author: rpopma <[email protected]> Authored: Mon Jan 22 23:50:03 2018 +0900 Committer: rpopma <[email protected]> Committed: Sun Jan 28 19:46:18 2018 +0900 ---------------------------------------------------------------------- .../logging/log4j/core/impl/Log4jLogEvent.java | 44 +++++++++++++------ .../core/pattern/DatePatternConverter.java | 2 +- .../logging/log4j/core/util/ClockFactory.java | 14 ++++-- .../apache/logging/log4j/core/util/Instant.java | 4 +- .../logging/log4j/core/util/MutableInstant.java | 9 +++- .../core/util/datetime/FixedDateFormat.java | 45 ++++++++++++-------- 6 files changed, 81 insertions(+), 37 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/d41ecf43/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java index 7332531..23a8dc0 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java @@ -284,7 +284,7 @@ public class Log4jLogEvent implements LogEvent { public Log4jLogEvent() { this(Strings.EMPTY, null, Strings.EMPTY, null, null, (Throwable) null, null, null, null, 0, null, - 0, null, CLOCK.currentTimeMillis(), 0, nanoClock.nanoTime()); + 0, null, CLOCK, nanoClock.nanoTime()); } /** @@ -328,13 +328,12 @@ public class Log4jLogEvent implements LogEvent { final Message message, final List<Property> properties, final Throwable t) { this(loggerName, marker, loggerFQCN, level, message, t, null, createContextData(properties), ThreadContext.getDepth() == 0 ? null : ThreadContext.cloneStack(), // mutable copy - 0, // thread name - null, // stack trace element - 0, - null, // LOG4J2-628 use log4j.Clock for timestamps - // LOG4J2-744 unless TimestampMessage already has one - message instanceof TimestampMessage ? ((TimestampMessage) message).getTimestamp() : - CLOCK.currentTimeMillis(), 0, nanoClock.nanoTime()); + 0, // thread id + null, // thread name + 0, // thread priority + null, // StackTraceElement source + CLOCK, // + nanoClock.nanoTime()); } /** @@ -415,6 +414,29 @@ public class Log4jLogEvent implements LogEvent { final StringMap contextData, final ThreadContext.ContextStack contextStack, final long threadId, final String threadName, final int threadPriority, final StackTraceElement source, final long timestampMillis, final int nanoOfMillisecond, final long nanoTime) { + this(loggerName, marker, loggerFQCN, level, message, thrown, thrownProxy, contextData, contextStack, threadId, threadName, threadPriority, source, nanoTime); + long millis = message instanceof TimestampMessage + ? ((TimestampMessage) message).getTimestamp() + : timestampMillis; + instant.initFromEpochMilli(millis, nanoOfMillisecond); + } + private Log4jLogEvent(final String loggerName, final Marker marker, final String loggerFQCN, final Level level, + final Message message, final Throwable thrown, final ThrowableProxy thrownProxy, + final StringMap contextData, final ThreadContext.ContextStack contextStack, final long threadId, + final String threadName, final int threadPriority, final StackTraceElement source, + final Clock clock, final long nanoTime) { + this(loggerName, marker, loggerFQCN, level, message, thrown, thrownProxy, contextData, contextStack, threadId, threadName, threadPriority, source, nanoTime); + if (message instanceof TimestampMessage) { + instant.initFromEpochMilli(((TimestampMessage) message).getTimestamp(), 0); + } else { + instant.initFrom(clock); + } + } + private Log4jLogEvent(final String loggerName, final Marker marker, final String loggerFQCN, final Level level, + final Message message, final Throwable thrown, final ThrowableProxy thrownProxy, + final StringMap contextData, final ThreadContext.ContextStack contextStack, final long threadId, + final String threadName, final int threadPriority, final StackTraceElement source, + final long nanoTime) { this.loggerName = loggerName; this.marker = marker; this.loggerFqcn = loggerFQCN; @@ -424,15 +446,11 @@ public class Log4jLogEvent implements LogEvent { this.thrownProxy = thrownProxy; this.contextData = contextData == null ? ContextDataFactory.createContextData() : contextData; this.contextStack = contextStack == null ? ThreadContext.EMPTY_STACK : contextStack; - long millis = message instanceof TimestampMessage - ? ((TimestampMessage) message).getTimestamp() - : timestampMillis; - this.instant.initFromEpochMilli(millis, nanoOfMillisecond); this.threadId = threadId; this.threadName = threadName; this.threadPriority = threadPriority; this.source = source; - if (message != null && message instanceof LoggerNameAwareMessage) { + if (message instanceof LoggerNameAwareMessage) { ((LoggerNameAwareMessage) message).setLoggerName(loggerName); } this.nanoTime = nanoTime; http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/d41ecf43/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 aa49ee4..3b5ce67 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 @@ -104,7 +104,7 @@ public final class DatePatternConverter extends LogEventPatternConverter impleme void formatToBuffer(final Instant instant, final StringBuilder destination) { final long epochSecond = instant.getEpochSecond(); final int nanoOfSecond = instant.getNanoOfSecond(); - if (previousTime != epochSecond && nanos != nanoOfSecond) { + if (previousTime != epochSecond || nanos != nanoOfSecond) { length = fixedDateFormat.formatInstant(instant, cachedBuffer, 0); previousTime = epochSecond; nanos = nanoOfSecond; http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/d41ecf43/log4j-core/src/main/java/org/apache/logging/log4j/core/util/ClockFactory.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/ClockFactory.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/ClockFactory.java index 31849af..7ba3fcc 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/ClockFactory.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/ClockFactory.java @@ -80,21 +80,27 @@ public final class ClockFactory { final String userRequest = PropertiesUtil.getProperties().getStringProperty(PROPERTY_NAME); if (userRequest == null) { LOGGER.trace("Using default SystemClock for timestamps."); - return new SystemClock(); + return logSupportedPrecision(new SystemClock()); } Supplier<Clock> specified = aliases().get(userRequest); if (specified != null) { LOGGER.trace("Using specified {} for timestamps.", userRequest); - return specified.get(); + return logSupportedPrecision(specified.get()); } try { final Clock result = Loader.newCheckedInstanceOf(userRequest, Clock.class); LOGGER.trace("Using {} for timestamps.", result.getClass().getName()); - return result; + return logSupportedPrecision(result); } catch (final Exception e) { final String fmt = "Could not create {}: {}, using default SystemClock for timestamps."; LOGGER.error(fmt, userRequest, e); - return new SystemClock(); + return logSupportedPrecision(new SystemClock()); } } + + private static Clock logSupportedPrecision(Clock clock) { + String support = clock instanceof PreciseClock ? "supports" : "does not support"; + LOGGER.debug("{} {} precise timestamps.", clock.getClass().getName(), support); + return clock; + } } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/d41ecf43/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Instant.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Instant.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Instant.java index a798021..baa9c80 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Instant.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/Instant.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.core.util; +import org.apache.logging.log4j.util.StringBuilderFormattable; + /** * Models a point in time, suitable for event timestamps. * <p> @@ -31,7 +33,7 @@ package org.apache.logging.log4j.core.util; * </p> * @since 2.11 */ -public interface Instant { +public interface Instant extends StringBuilderFormattable { /** * Gets the number of seconds from the Java epoch of 1970-01-01T00:00:00Z. * <p> http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/d41ecf43/log4j-core/src/main/java/org/apache/logging/log4j/core/util/MutableInstant.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/MutableInstant.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/MutableInstant.java index 1c64525..6ce378b 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/MutableInstant.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/MutableInstant.java @@ -147,6 +147,13 @@ public class MutableInstant implements Instant, Serializable { @Override public String toString() { - return "MutableInstant[epochSecond=" + epochSecond + ", nano=" + nanoOfSecond + "]"; + final StringBuilder sb = new StringBuilder(64); + formatTo(sb); + return sb.toString(); + } + + @Override + public void formatTo(final StringBuilder buffer) { + buffer.append("MutableInstant[epochSecond=").append(epochSecond).append(", nano=").append(nanoOfSecond).append("]"); } } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/d41ecf43/log4j-core/src/main/java/org/apache/logging/log4j/core/util/datetime/FixedDateFormat.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/datetime/FixedDateFormat.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/datetime/FixedDateFormat.java index b9b6af3..0d29178 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/datetime/FixedDateFormat.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/datetime/FixedDateFormat.java @@ -43,73 +43,73 @@ public class FixedDateFormat { /** * ABSOLUTE time format: {@code "HH:mm:ss,SSS"}. */ - ABSOLUTE("HH:mm:ss,SSS", null, 0, ':', 1, ',', 1), + ABSOLUTE("HH:mm:ss,SSS", null, 0, ':', 1, ',', 1, 3), /** * ABSOLUTE time format with microsecond precision: {@code "HH:mm:ss,nnnnnn"}. */ - ABSOLUTE_MICROS("HH:mm:ss,nnnnnn", null, 0, ':', 1, ',', 1), + ABSOLUTE_MICROS("HH:mm:ss,nnnnnn", null, 0, ':', 1, ',', 1, 6), /** * ABSOLUTE time format with nanosecond precision: {@code "HH:mm:ss,nnnnnnnnn"}. */ - ABSOLUTE_NANOS("HH:mm:ss,nnnnnnnnn", null, 0, ':', 1, ',', 1), + ABSOLUTE_NANOS("HH:mm:ss,nnnnnnnnn", null, 0, ':', 1, ',', 1, 9), /** * ABSOLUTE time format variation with period separator: {@code "HH:mm:ss.SSS"}. */ - ABSOLUTE_PERIOD("HH:mm:ss.SSS", null, 0, ':', 1, '.', 1), + ABSOLUTE_PERIOD("HH:mm:ss.SSS", null, 0, ':', 1, '.', 1, 3), /** * COMPACT time format: {@code "yyyyMMddHHmmssSSS"}. */ - COMPACT("yyyyMMddHHmmssSSS", "yyyyMMdd", 0, ' ', 0, ' ', 0), + COMPACT("yyyyMMddHHmmssSSS", "yyyyMMdd", 0, ' ', 0, ' ', 0, 3), /** * DATE_AND_TIME time format: {@code "dd MMM yyyy HH:mm:ss,SSS"}. */ - DATE("dd MMM yyyy HH:mm:ss,SSS", "dd MMM yyyy ", 0, ':', 1, ',', 1), + DATE("dd MMM yyyy HH:mm:ss,SSS", "dd MMM yyyy ", 0, ':', 1, ',', 1, 3), /** * DATE_AND_TIME time format variation with period separator: {@code "dd MMM yyyy HH:mm:ss.SSS"}. */ - DATE_PERIOD("dd MMM yyyy HH:mm:ss.SSS", "dd MMM yyyy ", 0, ':', 1, '.', 1), + DATE_PERIOD("dd MMM yyyy HH:mm:ss.SSS", "dd MMM yyyy ", 0, ':', 1, '.', 1, 3), /** * DEFAULT time format: {@code "yyyy-MM-dd HH:mm:ss,SSS"}. */ - DEFAULT("yyyy-MM-dd HH:mm:ss,SSS", "yyyy-MM-dd ", 0, ':', 1, ',', 1), + DEFAULT("yyyy-MM-dd HH:mm:ss,SSS", "yyyy-MM-dd ", 0, ':', 1, ',', 1, 3), /** * DEFAULT time format with microsecond precision: {@code "yyyy-MM-dd HH:mm:ss,nnnnnn"}. */ - DEFAULT_MICROS("yyyy-MM-dd HH:mm:ss,nnnnnn", "yyyy-MM-dd ", 0, ':', 1, ',', 1), + DEFAULT_MICROS("yyyy-MM-dd HH:mm:ss,nnnnnn", "yyyy-MM-dd ", 0, ':', 1, ',', 1, 6), /** * DEFAULT time format with nanosecond precision: {@code "yyyy-MM-dd HH:mm:ss,nnnnnnnnn"}. */ - DEFAULT_NANOS("yyyy-MM-dd HH:mm:ss,nnnnnnnnn", "yyyy-MM-dd ", 0, ':', 1, ',', 1), + DEFAULT_NANOS("yyyy-MM-dd HH:mm:ss,nnnnnnnnn", "yyyy-MM-dd ", 0, ':', 1, ',', 1, 9), /** * DEFAULT time format variation with period separator: {@code "yyyy-MM-dd HH:mm:ss.SSS"}. */ - DEFAULT_PERIOD("yyyy-MM-dd HH:mm:ss.SSS", "yyyy-MM-dd ", 0, ':', 1, '.', 1), + DEFAULT_PERIOD("yyyy-MM-dd HH:mm:ss.SSS", "yyyy-MM-dd ", 0, ':', 1, '.', 1, 3), /** * ISO8601_BASIC time format: {@code "yyyyMMdd'T'HHmmss,SSS"}. */ - ISO8601_BASIC("yyyyMMdd'T'HHmmss,SSS", "yyyyMMdd'T'", 2, ' ', 0, ',', 1), + ISO8601_BASIC("yyyyMMdd'T'HHmmss,SSS", "yyyyMMdd'T'", 2, ' ', 0, ',', 1, 3), /** * ISO8601_BASIC time format: {@code "yyyyMMdd'T'HHmmss.SSS"}. */ - ISO8601_BASIC_PERIOD("yyyyMMdd'T'HHmmss.SSS", "yyyyMMdd'T'", 2, ' ', 0, '.', 1), + ISO8601_BASIC_PERIOD("yyyyMMdd'T'HHmmss.SSS", "yyyyMMdd'T'", 2, ' ', 0, '.', 1, 3), /** * ISO8601 time format: {@code "yyyy-MM-dd'T'HH:mm:ss,SSS"}. */ - ISO8601("yyyy-MM-dd'T'HH:mm:ss,SSS", "yyyy-MM-dd'T'", 2, ':', 1, ',', 1), + ISO8601("yyyy-MM-dd'T'HH:mm:ss,SSS", "yyyy-MM-dd'T'", 2, ':', 1, ',', 1, 3), /** * ISO8601 time format: {@code "yyyy-MM-dd'T'HH:mm:ss.SSS"}. */ - ISO8601_PERIOD("yyyy-MM-dd'T'HH:mm:ss.SSS", "yyyy-MM-dd'T'", 2, ':', 1, '.', 1); + ISO8601_PERIOD("yyyy-MM-dd'T'HH:mm:ss.SSS", "yyyy-MM-dd'T'", 2, ':', 1, '.', 1, 3); private static final String DEFAULT_SECOND_FRACTION_PATTERN = "SSS"; private static final int MILLI_FRACTION_DIGITS = DEFAULT_SECOND_FRACTION_PATTERN.length(); @@ -122,9 +122,11 @@ public class FixedDateFormat { private final int timeSeparatorLength; private final char millisSeparatorChar; private final int millisSeparatorLength; + private final int secondFractionDigits; FixedFormat(final String pattern, final String datePattern, final int escapeCount, final char timeSeparator, - final int timeSepLength, final char millisSeparator, final int millisSepLength) { + final int timeSepLength, final char millisSeparator, final int millisSepLength, + final int secondFractionDigits) { this.timeSeparatorChar = timeSeparator; this.timeSeparatorLength = timeSepLength; this.millisSeparatorChar = millisSeparator; @@ -132,6 +134,7 @@ public class FixedDateFormat { this.pattern = Objects.requireNonNull(pattern); this.datePattern = datePattern; // may be null this.escapeCount = escapeCount; + this.secondFractionDigits = secondFractionDigits; } /** @@ -230,6 +233,14 @@ public class FixedDateFormat { public FastDateFormat getFastDateFormat(final TimeZone tz) { return getDatePattern() == null ? null : FastDateFormat.getInstance(getDatePattern(), tz); } + + /** + * Returns the number of digits specifying the fraction of the second to show + * @return 3 for millisecond precision, 6 for microsecond precision or 9 for nanosecond precision + */ + public int getSecondFractionDigits() { + return secondFractionDigits; + } } private final FixedFormat fixedFormat; @@ -264,7 +275,7 @@ public class FixedDateFormat { * @param tz time zone */ FixedDateFormat(final FixedFormat fixedFormat, final TimeZone tz) { - this(fixedFormat, tz, FixedFormat.DEFAULT_SECOND_FRACTION_PATTERN.length()); + this(fixedFormat, tz, fixedFormat.getSecondFractionDigits()); } /**
