Skip to content

Simplify async logger in main #2227

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Jan 23, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view

This file was deleted.

This file was deleted.

Original file line number Diff line number Diff line change
Expand Up @@ -302,9 +302,11 @@ protected static void assertAsyncLoggerConfig(final LoggerContext ctx, final int
final Configuration config = ctx.getConfiguration();
assertThat(config).isNotNull();
assertThat(config.getRootLogger()).isInstanceOf(AsyncLoggerConfig.class);
final AsyncLoggerConfigDisruptor disruptor = (AsyncLoggerConfigDisruptor) config.getAsyncLoggerConfigDelegate();
final Field sizeField = field(AsyncLoggerConfigDisruptor.class, "ringBufferSize");
assertThat(sizeField.get(disruptor)).isEqualTo(expectedBufferSize);
final AsyncLoggerConfigDisruptor disruptorWrapper =
(AsyncLoggerConfigDisruptor) config.getAsyncLoggerConfigDelegate();
final Disruptor<?> disruptor = (Disruptor<?>)
field(AsyncLoggerConfigDisruptor.class, "disruptor").get(disruptorWrapper);
assertThat(disruptor.getBufferSize()).isEqualTo(expectedBufferSize);
}

protected static void assertFormatMessagesInBackground() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,6 @@
import org.apache.logging.log4j.message.ReusableMessageFactory;
import org.apache.logging.log4j.message.SimpleMessage;
import org.apache.logging.log4j.spi.MutableThreadContextStack;
import org.apache.logging.log4j.util.StringMap;
import org.junit.jupiter.api.Tag;
import org.junit.jupiter.api.Test;

Expand Down Expand Up @@ -80,7 +79,7 @@ public void testIsPopulated() {
level,
data,
t,
(StringMap) evt.getContextData(),
evt.getContextData(),
contextStack,
-1,
threadName,
Expand Down Expand Up @@ -116,7 +115,7 @@ public void testGetLevelReturnsOffIfNullLevelSet() {
level,
data,
t,
(StringMap) evt.getContextData(),
evt.getContextData(),
contextStack,
-1,
threadName,
Expand Down Expand Up @@ -147,7 +146,7 @@ public void testGetMessageReturnsNonNullMessage() {
level,
data,
t,
(StringMap) evt.getContextData(),
evt.getContextData(),
contextStack,
-1,
threadName,
Expand Down Expand Up @@ -178,7 +177,7 @@ public void testGetMillisReturnsConstructorMillisForNormalMessage() {
level,
data,
t,
(StringMap) evt.getContextData(),
evt.getContextData(),
contextStack,
-1,
threadName,
Expand Down Expand Up @@ -210,15 +209,15 @@ public void testCreateMementoReturnsCopy() {
level,
data,
t,
(StringMap) evt.getContextData(),
evt.getContextData(),
contextStack,
-1,
threadName,
-1,
location,
new FixedPreciseClock(12345, 678),
new DummyNanoClock(1));
((StringMap) evt.getContextData()).putValue("key", "value");
evt.getContextData().putValue("key", "value");

final LogEvent actual = evt.toMemento();
assertEquals(evt.getLoggerName(), actual.getLoggerName());
Expand Down Expand Up @@ -261,15 +260,15 @@ public void testCreateMementoRetainsParametersAndFormat() {
level,
message,
t,
(StringMap) evt.getContextData(),
evt.getContextData(),
contextStack,
-1,
threadName,
-1,
location,
new FixedPreciseClock(12345, 678),
new DummyNanoClock(1));
((StringMap) evt.getContextData()).putValue("key", "value");
evt.getContextData().putValue("key", "value");

final Message actual = evt.toMemento().getMessage();
assertEquals("Hello {}!", actual.getFormat());
Expand Down Expand Up @@ -304,15 +303,15 @@ public void testMementoReuse() {
level,
message,
t,
(StringMap) evt.getContextData(),
evt.getContextData(),
contextStack,
-1,
threadName,
-1,
location,
new FixedPreciseClock(12345, 678),
new DummyNanoClock(1));
((StringMap) evt.getContextData()).putValue("key", "value");
evt.getContextData().putValue("key", "value");

final Message memento1 = evt.memento();
final Message memento2 = evt.memento();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,15 +16,14 @@
*/
package org.apache.logging.log4j.core.async;

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

/*
* (non-Javadoc)
*
* @see com.lmax.disruptor.EventTranslatorVararg#translateTo(java.lang.Object, long, java.lang.Object[])
*/
@Override
public void translateTo(final RingBufferLogEvent event, final long sequence, final Object... args) {
// Implementation note: candidate for optimization: exceeds 35 bytecodes.
final AsyncLogger asyncLogger = (AsyncLogger) args[0];
final StackTraceElement location = (StackTraceElement) args[1];
final String fqcn = (String) args[2];
final Level level = (Level) args[3];
final Marker marker = (Marker) args[4];
final Message message = (Message) args[5];
final Throwable thrown = (Throwable) args[6];

// needs shallow copy to be fast (LOG4J2-154)
final ContextStack contextStack = ThreadContext.getImmutableStack();

final Thread currentThread = Thread.currentThread();
event.setValues(
asyncLogger,
asyncLogger.getName(),
marker,
fqcn,
level,
message,
thrown,
// config properties are taken care of in the EventHandler thread
// in the AsyncLogger#actualAsyncLog method
contextDataInjector.injectContextData(null, (StringMap) event.getContextData()),
contextStack,
currentThread.getId(),
currentThread.getName(),
currentThread.getPriority(),
location,
clock,
nanoClock);
}

/**
* LOG4J2-471: prevent deadlock when RingBuffer is full and object being logged calls Logger.log() from its
* toString() method
Expand All @@ -340,7 +299,7 @@ void logMessageInCurrentThread(
*
* @param event the event to log
*/
public void actualAsyncLog(final RingBufferLogEvent event) {
public void actualAsyncLog(final ReusableLogEvent event) {
final LoggerConfig privateConfigLoggerConfig = privateConfig.loggerConfig;
final List<Property> properties = privateConfigLoggerConfig.getPropertyList();

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

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

private static StringMap getContextData(final RingBufferLogEvent event) {
private static StringMap getContextData(final ReusableLogEvent event) {
final StringMap contextData = event.getContextData();
if (contextData.isFrozen()) {
final StringMap temp = ContextDataFactory.createContextData();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -68,7 +68,7 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy
public static class Log4jEventWrapper {
public Log4jEventWrapper() {}

public Log4jEventWrapper(final MutableLogEvent mutableLogEvent) {
public Log4jEventWrapper(final LogEvent mutableLogEvent) {
event = mutableLogEvent;
}

Expand Down Expand Up @@ -107,8 +107,7 @@ public void setSequenceCallback(final Sequence sequenceCallback) {
}

@Override
public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch)
throws Exception {
public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch) {
event.event.setEndOfBatch(endOfBatch);
event.loggerConfig.logToAsyncLoggerConfigsOnCurrentThread(event.event);
event.clear();
Expand Down Expand Up @@ -159,13 +158,11 @@ private void notifyIntermediateProgress(final long sequence) {
ringBufferElement.loggerConfig = loggerConfig;
};

private int ringBufferSize;
private AsyncQueueFullPolicy asyncQueueFullPolicy;
private Boolean mutable = Boolean.FALSE;

private volatile Disruptor<Log4jEventWrapper> disruptor;
private long backgroundThreadId; // LOG4J2-471
private EventFactory<Log4jEventWrapper> factory;
private EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> translator;
private volatile boolean alreadyLoggedWarning;
private final AsyncWaitStrategyFactory asyncWaitStrategyFactory;
Expand Down Expand Up @@ -207,7 +204,8 @@ public void start() {
return;
}
LOGGER.trace("AsyncLoggerConfigDisruptor creating new disruptor for this configuration.");
ringBufferSize = DisruptorUtil.calculateRingBufferSize(Log4jPropertyKey.ASYNC_CONFIG_RING_BUFFER_SIZE);
final int ringBufferSize =
DisruptorUtil.calculateRingBufferSize(Log4jPropertyKey.ASYNC_CONFIG_RING_BUFFER_SIZE);
waitStrategy = DisruptorUtil.createWaitStrategy(
Log4jPropertyKey.ASYNC_CONFIG_WAIT_STRATEGY, asyncWaitStrategyFactory);

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

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

final ExceptionHandler<Log4jEventWrapper> errorHandler =
Expand Down
Loading