Skip to content

Commit 05ef38d

Browse files
ppkarwaszppkarwasz
committed
Simplify async logger in main
Due to the introduction of `Recycler` in `main` and related changes, many async loggers can be simplified: * no thread name caching is required, * in many methods we can use `ReusableLogEvent` instead of concrete classes, * many casts from `ReadOnlyStringMap` to `StringMap` are not necessary.
1 parent 0457ac6 commit 05ef38d

File tree

10 files changed

+33
-201
lines changed

10 files changed

+33
-201
lines changed

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerTestCachedThreadName.java‎

Lines changed: 0 additions & 63 deletions
This file was deleted.

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerTestUncachedThreadName.java‎

Lines changed: 0 additions & 62 deletions
This file was deleted.

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/QueueFullAbstractTest.java‎

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -302,9 +302,11 @@ protected static void assertAsyncLoggerConfig(final LoggerContext ctx, final int
302302
final Configuration config = ctx.getConfiguration();
303303
assertThat(config).isNotNull();
304304
assertThat(config.getRootLogger()).isInstanceOf(AsyncLoggerConfig.class);
305-
final AsyncLoggerConfigDisruptor disruptor = (AsyncLoggerConfigDisruptor) config.getAsyncLoggerConfigDelegate();
306-
final Field sizeField = field(AsyncLoggerConfigDisruptor.class, "ringBufferSize");
307-
assertThat(sizeField.get(disruptor)).isEqualTo(expectedBufferSize);
305+
final AsyncLoggerConfigDisruptor disruptorWrapper =
306+
(AsyncLoggerConfigDisruptor) config.getAsyncLoggerConfigDelegate();
307+
final Disruptor<?> disruptor = (Disruptor<?>)
308+
field(AsyncLoggerConfigDisruptor.class, "disruptor").get(disruptorWrapper);
309+
assertThat(disruptor.getBufferSize()).isEqualTo(expectedBufferSize);
308310
}
309311

310312
protected static void assertFormatMessagesInBackground() {

‎log4j-core-test/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java‎

Lines changed: 10 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -38,7 +38,6 @@
3838
import org.apache.logging.log4j.message.ReusableMessageFactory;
3939
import org.apache.logging.log4j.message.SimpleMessage;
4040
import org.apache.logging.log4j.spi.MutableThreadContextStack;
41-
import org.apache.logging.log4j.util.StringMap;
4241
import org.junit.jupiter.api.Tag;
4342
import org.junit.jupiter.api.Test;
4443

@@ -80,7 +79,7 @@ public void testIsPopulated() {
8079
level,
8180
data,
8281
t,
83-
(StringMap) evt.getContextData(),
82+
evt.getContextData(),
8483
contextStack,
8584
-1,
8685
threadName,
@@ -116,7 +115,7 @@ public void testGetLevelReturnsOffIfNullLevelSet() {
116115
level,
117116
data,
118117
t,
119-
(StringMap) evt.getContextData(),
118+
evt.getContextData(),
120119
contextStack,
121120
-1,
122121
threadName,
@@ -147,7 +146,7 @@ public void testGetMessageReturnsNonNullMessage() {
147146
level,
148147
data,
149148
t,
150-
(StringMap) evt.getContextData(),
149+
evt.getContextData(),
151150
contextStack,
152151
-1,
153152
threadName,
@@ -178,7 +177,7 @@ public void testGetMillisReturnsConstructorMillisForNormalMessage() {
178177
level,
179178
data,
180179
t,
181-
(StringMap) evt.getContextData(),
180+
evt.getContextData(),
182181
contextStack,
183182
-1,
184183
threadName,
@@ -210,15 +209,15 @@ public void testCreateMementoReturnsCopy() {
210209
level,
211210
data,
212211
t,
213-
(StringMap) evt.getContextData(),
212+
evt.getContextData(),
214213
contextStack,
215214
-1,
216215
threadName,
217216
-1,
218217
location,
219218
new FixedPreciseClock(12345, 678),
220219
new DummyNanoClock(1));
221-
((StringMap) evt.getContextData()).putValue("key", "value");
220+
evt.getContextData().putValue("key", "value");
222221

223222
final LogEvent actual = evt.toMemento();
224223
assertEquals(evt.getLoggerName(), actual.getLoggerName());
@@ -261,15 +260,15 @@ public void testCreateMementoRetainsParametersAndFormat() {
261260
level,
262261
message,
263262
t,
264-
(StringMap) evt.getContextData(),
263+
evt.getContextData(),
265264
contextStack,
266265
-1,
267266
threadName,
268267
-1,
269268
location,
270269
new FixedPreciseClock(12345, 678),
271270
new DummyNanoClock(1));
272-
((StringMap) evt.getContextData()).putValue("key", "value");
271+
evt.getContextData().putValue("key", "value");
273272

274273
final Message actual = evt.toMemento().getMessage();
275274
assertEquals("Hello {}!", actual.getFormat());
@@ -304,15 +303,15 @@ public void testMementoReuse() {
304303
level,
305304
message,
306305
t,
307-
(StringMap) evt.getContextData(),
306+
evt.getContextData(),
308307
contextStack,
309308
-1,
310309
threadName,
311310
-1,
312311
location,
313312
new FixedPreciseClock(12345, 678),
314313
new DummyNanoClock(1));
315-
((StringMap) evt.getContextData()).putValue("key", "value");
314+
evt.getContextData().putValue("key", "value");
316315

317316
final Message memento1 = evt.memento();
318317
final Message memento2 = evt.memento();

‎log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java‎

Lines changed: 5 additions & 46 deletions
Original file line numberDiff line numberDiff line change
@@ -16,15 +16,14 @@
1616
*/
1717
package org.apache.logging.log4j.core.async;
1818

19-
import com.lmax.disruptor.EventTranslatorVararg;
2019
import java.util.List;
2120
import org.apache.logging.log4j.Level;
2221
import org.apache.logging.log4j.Marker;
2322
import org.apache.logging.log4j.ThreadContext;
24-
import org.apache.logging.log4j.ThreadContext.ContextStack;
2523
import org.apache.logging.log4j.core.ContextDataInjector;
2624
import org.apache.logging.log4j.core.Logger;
2725
import org.apache.logging.log4j.core.LoggerContext;
26+
import org.apache.logging.log4j.core.ReusableLogEvent;
2827
import org.apache.logging.log4j.core.config.Configuration;
2928
import org.apache.logging.log4j.core.config.LoggerConfig;
3029
import org.apache.logging.log4j.core.config.Property;
@@ -58,7 +57,7 @@
5857
* and they will flush to disk at the end of each batch. This means that even with immediateFlush=false, there will
5958
* never be any items left in the buffer; all log events will all be written to disk in a very efficient manner.
6059
*/
61-
public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBufferLogEvent> {
60+
public class AsyncLogger extends Logger {
6261
// Implementation note: many methods in this class are tuned for performance. MODIFY WITH CARE!
6362
// Specifically, try to keep the hot methods to 35 bytecodes or less:
6463
// this is within the MaxInlineSize threshold and makes these methods candidates for
@@ -276,46 +275,6 @@ private StackTraceElement calcLocationIfRequested(final String fqcn) {
276275
return includeLocation ? StackLocatorUtil.calcLocation(fqcn) : null;
277276
}
278277

279-
/*
280-
* (non-Javadoc)
281-
*
282-
* @see com.lmax.disruptor.EventTranslatorVararg#translateTo(java.lang.Object, long, java.lang.Object[])
283-
*/
284-
@Override
285-
public void translateTo(final RingBufferLogEvent event, final long sequence, final Object... args) {
286-
// Implementation note: candidate for optimization: exceeds 35 bytecodes.
287-
final AsyncLogger asyncLogger = (AsyncLogger) args[0];
288-
final StackTraceElement location = (StackTraceElement) args[1];
289-
final String fqcn = (String) args[2];
290-
final Level level = (Level) args[3];
291-
final Marker marker = (Marker) args[4];
292-
final Message message = (Message) args[5];
293-
final Throwable thrown = (Throwable) args[6];
294-
295-
// needs shallow copy to be fast (LOG4J2-154)
296-
final ContextStack contextStack = ThreadContext.getImmutableStack();
297-
298-
final Thread currentThread = Thread.currentThread();
299-
event.setValues(
300-
asyncLogger,
301-
asyncLogger.getName(),
302-
marker,
303-
fqcn,
304-
level,
305-
message,
306-
thrown,
307-
// config properties are taken care of in the EventHandler thread
308-
// in the AsyncLogger#actualAsyncLog method
309-
contextDataInjector.injectContextData(null, (StringMap) event.getContextData()),
310-
contextStack,
311-
currentThread.getId(),
312-
currentThread.getName(),
313-
currentThread.getPriority(),
314-
location,
315-
clock,
316-
nanoClock);
317-
}
318-
319278
/**
320279
* LOG4J2-471: prevent deadlock when RingBuffer is full and object being logged calls Logger.log() from its
321280
* toString() method
@@ -340,7 +299,7 @@ void logMessageInCurrentThread(
340299
*
341300
* @param event the event to log
342301
*/
343-
public void actualAsyncLog(final RingBufferLogEvent event) {
302+
public void actualAsyncLog(final ReusableLogEvent event) {
344303
final LoggerConfig privateConfigLoggerConfig = privateConfig.loggerConfig;
345304
final List<Property> properties = privateConfigLoggerConfig.getPropertyList();
346305

@@ -352,7 +311,7 @@ public void actualAsyncLog(final RingBufferLogEvent event) {
352311
}
353312

354313
@SuppressWarnings("ForLoopReplaceableByForEach") // Avoid iterator allocation
355-
private void onPropertiesPresent(final RingBufferLogEvent event, final List<Property> properties) {
314+
private void onPropertiesPresent(final ReusableLogEvent event, final List<Property> properties) {
356315
final StringMap contextData = getContextData(event);
357316
for (int i = 0, size = properties.size(); i < size; i++) {
358317
final Property prop = properties.get(i);
@@ -367,7 +326,7 @@ private void onPropertiesPresent(final RingBufferLogEvent event, final List<Prop
367326
event.setContextData(contextData);
368327
}
369328

370-
private static StringMap getContextData(final RingBufferLogEvent event) {
329+
private static StringMap getContextData(final ReusableLogEvent event) {
371330
final StringMap contextData = event.getContextData();
372331
if (contextData.isFrozen()) {
373332
final StringMap temp = ContextDataFactory.createContextData();

‎log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigDisruptor.java‎

Lines changed: 5 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -68,7 +68,7 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy
6868
public static class Log4jEventWrapper {
6969
public Log4jEventWrapper() {}
7070

71-
public Log4jEventWrapper(final MutableLogEvent mutableLogEvent) {
71+
public Log4jEventWrapper(final LogEvent mutableLogEvent) {
7272
event = mutableLogEvent;
7373
}
7474

@@ -107,8 +107,7 @@ public void setSequenceCallback(final Sequence sequenceCallback) {
107107
}
108108

109109
@Override
110-
public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch)
111-
throws Exception {
110+
public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch) {
112111
event.event.setEndOfBatch(endOfBatch);
113112
event.loggerConfig.logToAsyncLoggerConfigsOnCurrentThread(event.event);
114113
event.clear();
@@ -159,13 +158,11 @@ private void notifyIntermediateProgress(final long sequence) {
159158
ringBufferElement.loggerConfig = loggerConfig;
160159
};
161160

162-
private int ringBufferSize;
163161
private AsyncQueueFullPolicy asyncQueueFullPolicy;
164162
private Boolean mutable = Boolean.FALSE;
165163

166164
private volatile Disruptor<Log4jEventWrapper> disruptor;
167165
private long backgroundThreadId; // LOG4J2-471
168-
private EventFactory<Log4jEventWrapper> factory;
169166
private EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> translator;
170167
private volatile boolean alreadyLoggedWarning;
171168
private final AsyncWaitStrategyFactory asyncWaitStrategyFactory;
@@ -207,7 +204,8 @@ public void start() {
207204
return;
208205
}
209206
LOGGER.trace("AsyncLoggerConfigDisruptor creating new disruptor for this configuration.");
210-
ringBufferSize = DisruptorUtil.calculateRingBufferSize(Log4jPropertyKey.ASYNC_CONFIG_RING_BUFFER_SIZE);
207+
final int ringBufferSize =
208+
DisruptorUtil.calculateRingBufferSize(Log4jPropertyKey.ASYNC_CONFIG_RING_BUFFER_SIZE);
211209
waitStrategy = DisruptorUtil.createWaitStrategy(
212210
Log4jPropertyKey.ASYNC_CONFIG_WAIT_STRATEGY, asyncWaitStrategyFactory);
213211

@@ -223,7 +221,7 @@ public Thread newThread(final Runnable r) {
223221
asyncQueueFullPolicy = AsyncQueueFullPolicyFactory.create();
224222

225223
translator = mutable ? MUTABLE_TRANSLATOR : TRANSLATOR;
226-
factory = mutable ? MUTABLE_FACTORY : FACTORY;
224+
final EventFactory<Log4jEventWrapper> factory = mutable ? MUTABLE_FACTORY : FACTORY;
227225
disruptor = new Disruptor<>(factory, ringBufferSize, threadFactory, ProducerType.MULTI, waitStrategy);
228226

229227
final ExceptionHandler<Log4jEventWrapper> errorHandler =

0 commit comments

Comments
 (0)