You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by ck...@apache.org on 2019/05/22 21:02:32 UTC
[logging-log4j2] 03/06: Update enqueue from synchronized to a
Semaphore for more configurability
This is an automated email from the ASF dual-hosted git repository.
ckozak pushed a commit to branch LOG4J2-2606
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
commit 14ca876d587f9d3ef4d2202c9788cbe31a29ac92
Author: Carter Kozak <ck...@apache.org>
AuthorDate: Wed May 22 14:06:00 2019 -0400
Update enqueue from synchronized to a Semaphore for more configurability
---
.../logging/log4j/core/async/AsyncLoggerDisruptor.java | 18 ++++++++++++++----
.../apache/logging/log4j/core/async/DisruptorUtil.java | 5 +++--
.../perf/jmh/ConcurrentAsyncLoggerToFileBenchmark.java | 2 +-
3 files changed, 18 insertions(+), 7 deletions(-)
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDisruptor.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDisruptor.java
index b827f8c..1e294e4 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDisruptor.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDisruptor.java
@@ -17,6 +17,7 @@
package org.apache.logging.log4j.core.async;
+import java.util.concurrent.Semaphore;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
@@ -46,7 +47,10 @@ class AsyncLoggerDisruptor extends AbstractLifeCycle {
private static final int SLEEP_MILLIS_BETWEEN_DRAIN_ATTEMPTS = 50;
private static final int MAX_DRAIN_ATTEMPTS_BEFORE_SHUTDOWN = 200;
- private final Object queueFullEnqueueLock = new Object();
+ // queueFullEnqueueSemaphore is null when the semaphore is disabled (non-positive value)
+ private final Semaphore queueFullEnqueueSemaphore = DisruptorUtil.ASYNC_LOGGER_ENQUEUE_SEMAPHORE_PERMITS > 0
+ ? new Semaphore(DisruptorUtil.ASYNC_LOGGER_ENQUEUE_SEMAPHORE_PERMITS)
+ : null;
private volatile Disruptor<RingBufferLogEvent> disruptor;
private String contextName;
@@ -226,8 +230,11 @@ class AsyncLoggerDisruptor extends AbstractLifeCycle {
// Avoiding this and using an older reference could result in adding a log event to the disruptor after it
// was shut down, which could cause the publishEvent method to hang and never return.
if (synchronizeEnqueueWhenQueueFull()) {
- synchronized (queueFullEnqueueLock) {
+ queueFullEnqueueSemaphore.acquireUninterruptibly();
+ try {
disruptor.publishEvent(translator);
+ } finally {
+ queueFullEnqueueSemaphore.release();
}
} else {
disruptor.publishEvent(translator);
@@ -252,7 +259,8 @@ class AsyncLoggerDisruptor extends AbstractLifeCycle {
// Avoiding this and using an older reference could result in adding a log event to the disruptor after it
// was shut down, which could cause the publishEvent method to hang and never return.
if (synchronizeEnqueueWhenQueueFull()) {
- synchronized (queueFullEnqueueLock) {
+ queueFullEnqueueSemaphore.acquireUninterruptibly();
+ try {
disruptor.getRingBuffer().publishEvent(translator,
asyncLogger, // asyncLogger: 0
location, // location: 1
@@ -261,6 +269,8 @@ class AsyncLoggerDisruptor extends AbstractLifeCycle {
marker, // 4
msg, // 5
thrown); // 6
+ } finally {
+ queueFullEnqueueSemaphore.release();
}
} else {
disruptor.getRingBuffer().publishEvent(translator,
@@ -281,7 +291,7 @@ class AsyncLoggerDisruptor extends AbstractLifeCycle {
}
private boolean synchronizeEnqueueWhenQueueFull() {
- return DisruptorUtil.SYNCHRONIZE_ENQUEUE_WHEN_QUEUE_IS_FULL
+ return queueFullEnqueueSemaphore != null
// Background thread must never block
&& backgroundThreadId != Thread.currentThread().getId();
}
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/DisruptorUtil.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/DisruptorUtil.java
index 59d2a7e..6e868f8 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/DisruptorUtil.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/DisruptorUtil.java
@@ -48,8 +48,9 @@ final class DisruptorUtil {
// LOG4J2-2606: Disruptor spins enqueuing events across multiple threads when the queue is full.
// CPU utilization is significantly reduced by restricting access to the enqueue operation.
- static final boolean SYNCHRONIZE_ENQUEUE_WHEN_QUEUE_IS_FULL = PropertiesUtil.getProperties()
- .getBooleanProperty("AsyncLogger.SynchronizeEnqueueWhenQueueFull", true);
+ // Non-positive values disable the semaphore.
+ static final int ASYNC_LOGGER_ENQUEUE_SEMAPHORE_PERMITS = PropertiesUtil.getProperties()
+ .getIntegerProperty("AsyncLogger.AsyncQueueFullEnqueueSemaphorePermits", 1);
private DisruptorUtil() {
}
diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConcurrentAsyncLoggerToFileBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConcurrentAsyncLoggerToFileBenchmark.java
index 20415f0..2e9d3fe 100644
--- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConcurrentAsyncLoggerToFileBenchmark.java
+++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ConcurrentAsyncLoggerToFileBenchmark.java
@@ -103,7 +103,7 @@ public class ConcurrentAsyncLoggerToFileBenchmark {
ENQUEUE(Collections.singletonMap("log4j2.AsyncQueueFullPolicy", "Default")),
ENQUEUE_UNSYNCHRONIZED(new HashMap<>() {{
put("log4j2.AsyncQueueFullPolicy", "Default");
- put("log4j2.AsyncLogger.SynchronizeEnqueueWhenQueueFull", "false");
+ put("AsyncLogger.AsyncQueueFullEnqueueSemaphorePermits", "0");
}
}),
SYNCHRONOUS(Collections.singletonMap("log4j2.AsyncQueueFullPolicy",