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 2016/03/22 16:22:07 UTC
logging-log4j2 git commit: refactor AsyncLogger,
RingBufferLogEvent and RingBufferLogEventTranslator: these changes
resulted in a 10% increase in throughput
Repository: logging-log4j2
Updated Branches:
refs/heads/master 15ce6e6f1 -> b53e048d1
refactor AsyncLogger, RingBufferLogEvent and RingBufferLogEventTranslator: these changes resulted in a 10% increase in throughput
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/b53e048d
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/b53e048d
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/b53e048d
Branch: refs/heads/master
Commit: b53e048d1e3f09c96db3d11790438f8ef6b4f4fc
Parents: 15ce6e6
Author: rpopma <rp...@apache.org>
Authored: Wed Mar 23 00:22:07 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Wed Mar 23 00:22:07 2016 +0900
----------------------------------------------------------------------
.../logging/log4j/core/async/AsyncLogger.java | 31 ++++++++--------
.../log4j/core/async/RingBufferLogEvent.java | 39 ++++++++++++++------
.../async/RingBufferLogEventTranslator.java | 9 +++--
3 files changed, 48 insertions(+), 31 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b53e048d/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
index 8817b29..f661648 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
@@ -74,8 +74,7 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
private final ThreadLocal<RingBufferLogEventTranslator> threadLocalTranslator = new ThreadLocal<>();
private final AsyncLoggerDisruptor loggerDisruptor;
- // Reconfigurable. Volatile field nanoClock is always updated later, so no need to make includeLocation volatile.
- private boolean includeLocation;
+ private volatile boolean includeLocation; // reconfigurable
private volatile NanoClock nanoClock; // reconfigurable
/**
@@ -101,9 +100,9 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
*/
@Override
protected void updateConfiguration(Configuration newConfig) {
- super.updateConfiguration(newConfig);
- includeLocation = privateConfig.loggerConfig.isIncludeLocation();
nanoClock = newConfig.getNanoClock();
+ includeLocation = newConfig.getLoggerConfig(name).isIncludeLocation();
+ super.updateConfiguration(newConfig);
LOGGER.trace("[{}] AsyncLogger {} uses {}.", getContext().getName(), getName(), nanoClock);
}
@@ -125,11 +124,6 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message,
final Throwable thrown) {
- // if the Message instance is reused, there is no point in freezing its message here
- if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND && !isReused(message)) { // LOG4J2-898: user may choose
- message.getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
- }
-
if (loggerDisruptor.isUseThreadLocals()) {
logWithThreadLocalTranslator(fqcn, level, marker, message, thrown);
} else {
@@ -160,6 +154,11 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
final RingBufferLogEventTranslator translator = getCachedTranslator();
initTranslator(translator, fqcn, level, marker, message, thrown);
+ initTranslatorThreadValues(translator);
+ publish(translator);
+ }
+
+ private void publish(final RingBufferLogEventTranslator translator) {
if (!loggerDisruptor.tryPublish(translator)) {
handleRingBufferFull(translator);
}
@@ -202,14 +201,12 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
eventTimeMillis(message), //
nanoClock.nanoTime() //
);
+ }
+
+ private void initTranslatorThreadValues(final RingBufferLogEventTranslator translator) {
// constant check should be optimized out when using default (CACHED)
if (THREAD_NAME_CACHING_STRATEGY == ThreadNameCachingStrategy.UNCACHED) {
- final Thread currentThread = Thread.currentThread();
- translator.setThreadValues(
- currentThread.getId(), //
- currentThread.getName(), //
- currentThread.getPriority() //
- );
+ translator.updateThreadValues();
}
}
@@ -258,6 +255,10 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
LOGGER.error("Ignoring log event after Log4j has been shut down.");
return;
}
+ // if the Message instance is reused, there is no point in freezing its message here
+ if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND && !isReused(message)) { // LOG4J2-898: user may choose
+ message.getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
+ }
// calls the translateTo method on this AsyncLogger
disruptor.getRingBuffer().publishEvent(this, this, calcLocationIfRequested(fqcn), fqcn, level, marker, message,
thrown);
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b53e048d/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
index d4669f7..156261c 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
@@ -139,17 +139,6 @@ public class RingBufferLogEvent implements LogEvent {
this.marker = aMarker;
this.fqcn = theFqcn;
this.level = aLevel;
- if (msg instanceof ReusableMessage) {
- if (messageText == null) {
- // Should never happen:
- // only happens if user logs a custom reused message when Constants.ENABLE_THREADLOCALS is false
- messageText = new StringBuilder(INITIAL_REUSABLE_MESSAGE_SIZE);
- }
- messageText.setLength(0);
- ((ReusableMessage) msg).formatTo(messageText);
- } else {
- this.message = msg;
- }
this.thrown = aThrowable;
this.thrownProxy = null;
this.contextMap = aMap;
@@ -160,6 +149,29 @@ public class RingBufferLogEvent implements LogEvent {
this.location = aLocation;
this.currentTimeMillis = aCurrentTimeMillis;
this.nanoTime = aNanoTime;
+ setMessage(msg);
+ }
+
+ private void setMessage(final Message msg) {
+ if (msg instanceof ReusableMessage) {
+ ((ReusableMessage) msg).formatTo(getMessageTextForWriting());
+ } else {
+ // if the Message instance is reused, there is no point in freezing its message here
+ if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND) { // LOG4J2-898: user may choose
+ msg.getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
+ }
+ this.message = msg;
+ }
+ }
+
+ private StringBuilder getMessageTextForWriting() {
+ if (messageText == null) {
+ // Should never happen:
+ // only happens if user logs a custom reused message when Constants.ENABLE_THREADLOCALS is false
+ messageText = new StringBuilder(INITIAL_REUSABLE_MESSAGE_SIZE);
+ }
+ messageText.setLength(0);
+ return messageText;
}
/**
@@ -345,8 +357,11 @@ public class RingBufferLogEvent implements LogEvent {
null,
0, 0 // nanoTime
);
+ trimMessageText();
+ }
- // ensure that excessively long char[] arrays are not kept in memory forever
+ // ensure that excessively long char[] arrays are not kept in memory forever
+ private void trimMessageText() {
if (messageText != null && messageText.length() > MAX_REUSABLE_MESSAGE_SIZE) {
messageText.setLength(MAX_REUSABLE_MESSAGE_SIZE);
messageText.trimToSize();
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b53e048d/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java
index da15ed6..51bd795 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java
@@ -95,9 +95,10 @@ public class RingBufferLogEventTranslator implements
this.nanoTime = aNanoTime;
}
- public void setThreadValues(final long threadId, final String threadName, final int threadPriority) {
- this.threadId = threadId;
- this.threadName = threadName;
- this.threadPriority = threadPriority;
+ public void updateThreadValues() {
+ final Thread currentThread = Thread.currentThread();
+ this.threadId = currentThread.getId();
+ this.threadName = currentThread.getName();
+ this.threadPriority = currentThread.getPriority();
}
}