Skip to content
Open
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
129 changes: 126 additions & 3 deletions logback-core/src/main/java/ch/qos/logback/core/AsyncAppenderBase.java
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
import java.util.List;
import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.BlockingQueue;
import java.util.concurrent.atomic.LongAdder;

/**
* This appender and derived classes, log events asynchronously. In order to
Expand Down Expand Up @@ -70,6 +71,13 @@ public class AsyncAppenderBase<E> extends UnsynchronizedAppenderBase<E> implemen
public static final int DEFAULT_MAX_FLUSH_TIME = 1000;
int maxFlushTime = DEFAULT_MAX_FLUSH_TIME;

// Metrics counters for observability
private final LongAdder totalAppendedCount = new LongAdder();
private final LongAdder discardedByThresholdCount = new LongAdder();
private final LongAdder discardedByQueueFullCount = new LongAdder();
private final LongAdder dispatchedCount = new LongAdder();
private final LongAdder failedDispatchCount = new LongAdder();

/**
* Is the eventObject passed as parameter discardable? The base class's
* implementation of this method always returns 'false' but sub-classes may (and
Expand Down Expand Up @@ -159,7 +167,9 @@ public void stop() {

@Override
protected void append(E eventObject) {
totalAppendedCount.increment();
if (isQueueBelowDiscardingThreshold() && isDiscardable(eventObject)) {
discardedByThresholdCount.increment();
return;
}
preprocess(eventObject);
Expand All @@ -172,7 +182,10 @@ public boolean isQueueBelowDiscardingThreshold() {

private void put(E eventObject) {
if (neverBlock) {
blockingQueue.offer(eventObject);
boolean offered = blockingQueue.offer(eventObject);
if (!offered) {
discardedByQueueFullCount.increment();
}
} else {
putUninterruptibly(eventObject);
}
Expand Down Expand Up @@ -250,6 +263,96 @@ public int getRemainingCapacity() {
return blockingQueue.remainingCapacity();
}

// ========== Metrics for observability ==========

/**
* Returns the total number of events that have been submitted to this appender
* for logging. This includes events that were successfully queued as well as
* events that were discarded.
*
* @return total number of events submitted to append()
* @since 1.5.27
*/
public long getTotalAppendedCount() {
return totalAppendedCount.sum();
}

/**
* Returns the number of events that were discarded because the queue was
* nearly full (remaining capacity below discarding threshold) and the event
* was deemed discardable by the {@link #isDiscardable(Object)} method.
*
* @return number of events discarded due to threshold policy
* @since 1.5.27
*/
public long getDiscardedByThresholdCount() {
return discardedByThresholdCount.sum();
}

/**
* Returns the number of events that were discarded because the queue was
* completely full and {@link #neverBlock} was set to true. In this mode,
* when the queue cannot accept new events, they are dropped immediately.
*
* @return number of events discarded due to full queue in non-blocking mode
* @since 1.5.27
*/
public long getDiscardedByQueueFullCount() {
return discardedByQueueFullCount.sum();
}

/**
* Returns the total number of events that were discarded for any reason.
* This is the sum of {@link #getDiscardedByThresholdCount()} and
* {@link #getDiscardedByQueueFullCount()}.
*
* @return total number of discarded events
* @since 1.5.27
*/
public long getTotalDiscardedCount() {
return discardedByThresholdCount.sum() + discardedByQueueFullCount.sum();
}

/**
* Returns the number of events that have been successfully dispatched to
* the attached appender by the worker thread. This represents the "output"
* side of the async appender and can be compared with {@link #getTotalAppendedCount()}
* to understand how many events are currently in-flight in the queue.
*
* @return number of events dispatched to the attached appender
* @since 1.5.27
*/
public long getDispatchedCount() {
return dispatchedCount.sum();
}

/**
* Returns the number of events that failed to be dispatched to the attached
* appender due to an exception. Note that most appenders catch exceptions
* internally, so this counter primarily tracks uncaught exceptions that
* propagate from the appender.
*
* @return number of events that failed during dispatch
* @since 1.5.27
*/
public long getFailedDispatchCount() {
return failedDispatchCount.sum();
}

/**
* Resets all metrics counters to zero. This can be useful for testing or
* when you want to start fresh metrics collection at a specific point in time.
*
* @since 1.5.27
*/
public void resetMetrics() {
totalAppendedCount.reset();
discardedByThresholdCount.reset();
discardedByQueueFullCount.reset();
dispatchedCount.reset();
failedDispatchCount.reset();
}

public void addAppender(Appender<E> newAppender) {
if (appenderCount == 0) {
appenderCount++;
Expand Down Expand Up @@ -298,9 +401,19 @@ public void run() {
E e0 = parent.blockingQueue.take();
elements.add(e0);
parent.blockingQueue.drainTo(elements);
int dispatched = 0;
int failed = 0;
for (E e : elements) {
aai.appendLoopOnAppenders(e);
try {
aai.appendLoopOnAppenders(e);
dispatched++;
} catch (Exception ex) {
failed++;
parent.addError("Failed to dispatch event to appender", ex);
}
}
parent.dispatchedCount.add(dispatched);
parent.failedDispatchCount.add(failed);
} catch (InterruptedException e1) {
// exit if interrupted
break;
Expand All @@ -309,10 +422,20 @@ public void run() {

addInfo("Worker thread will flush remaining events before exiting. ");

int dispatched = 0;
int failed = 0;
for (E e : parent.blockingQueue) {
aai.appendLoopOnAppenders(e);
try {
aai.appendLoopOnAppenders(e);
dispatched++;
} catch (Exception ex) {
failed++;
parent.addError("Failed to dispatch event to appender", ex);
}
parent.blockingQueue.remove(e);
}
parent.dispatchedCount.add(dispatched);
parent.failedDispatchCount.add(failed);

aai.detachAndStopAllAppenders();
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -332,4 +332,194 @@ public void checkThatStartMethodIsIdempotent() {
// thread
asyncAppenderBase.start();
}

// ========== Metrics tests ==========

@Test
@Timeout(value = 2, unit = TimeUnit.SECONDS)
public void metricsTotalAppendedCount() {
asyncAppenderBase.addAppender(listAppender);
asyncAppenderBase.start();
int loopLen = 10;
for (int i = 0; i < loopLen; i++) {
asyncAppenderBase.doAppend(i);
}
asyncAppenderBase.stop();
Assertions.assertEquals(loopLen, asyncAppenderBase.getTotalAppendedCount());
}

@Test
@Timeout(value = 2, unit = TimeUnit.SECONDS)
public void metricsDiscardedByThreshold() {
// Create fresh instances to avoid state from other tests
LossyAsyncAppender freshLossyAppender = new LossyAsyncAppender();
freshLossyAppender.setContext(context);
DelayingListAppender<Integer> freshDelayingAppender = new DelayingListAppender<>();
freshDelayingAppender.setContext(context);
freshDelayingAppender.setName("freshDelaying");
freshDelayingAppender.setDelay(50); // Long delay to ensure queue fills up reliably
freshDelayingAppender.start();

int bufferSize = 5;
int loopLen = bufferSize * 4; // More events to ensure threshold is reached
freshLossyAppender.addAppender(freshDelayingAppender);
freshLossyAppender.setQueueSize(bufferSize);
freshLossyAppender.setDiscardingThreshold(2); // Higher threshold for more reliable triggering
freshLossyAppender.setMaxFlushTime(2000);
freshLossyAppender.start();
for (int i = 0; i < loopLen; i++) {
freshLossyAppender.doAppend(i);
}
freshLossyAppender.stop();

// Total appended should be loopLen
Assertions.assertEquals(loopLen, freshLossyAppender.getTotalAppendedCount());

// Discards by threshold should be tracked when discardable events
// are dropped due to queue being nearly full.
long discardedByThreshold = freshLossyAppender.getDiscardedByThresholdCount();
Assertions.assertTrue(discardedByThreshold > 0,
"Expected some events to be discarded by threshold, but got " + discardedByThreshold);

// No events discarded by queue full since neverBlock is false
Assertions.assertEquals(0, freshLossyAppender.getDiscardedByQueueFullCount());

// Verify consistency: total appended = received + discarded
long totalDiscarded = freshLossyAppender.getTotalDiscardedCount();
int received = freshDelayingAppender.list.size();
Assertions.assertEquals(loopLen, received + totalDiscarded,
"Total appended should equal received + discarded");
}

@Test
@Timeout(value = 2, unit = TimeUnit.SECONDS)
public void metricsDiscardedByQueueFull() {
int bufferSize = 10;
int loopLen = bufferSize * 200;
delayingListAppender.setDelay(5);
asyncAppenderBase.addAppender(delayingListAppender);
asyncAppenderBase.setQueueSize(bufferSize);
asyncAppenderBase.setNeverBlock(true);
asyncAppenderBase.start();
for (int i = 0; i < loopLen; i++) {
asyncAppenderBase.doAppend(i);
}
asyncAppenderBase.stop();

// Total appended should be loopLen
Assertions.assertEquals(loopLen, asyncAppenderBase.getTotalAppendedCount());

// No discards by threshold (base class isDiscardable returns false)
Assertions.assertEquals(0, asyncAppenderBase.getDiscardedByThresholdCount());

// Some events should be discarded by queue full since neverBlock is true
// and the queue can't keep up with the rate of events
Assertions.assertTrue(asyncAppenderBase.getDiscardedByQueueFullCount() > 0,
"Expected some events to be discarded due to full queue");

// Total discarded should match queue full discards
Assertions.assertEquals(asyncAppenderBase.getDiscardedByQueueFullCount(),
asyncAppenderBase.getTotalDiscardedCount());
}

@Test
@Timeout(value = 2, unit = TimeUnit.SECONDS)
public void metricsResetWorks() {
// Use fresh instances to avoid test pollution
AsyncAppenderBase<Integer> freshAsyncAppender = new AsyncAppenderBase<>();
freshAsyncAppender.setContext(context);
ListAppender<Integer> freshListAppender = new ListAppender<>();
freshListAppender.setContext(context);
freshListAppender.setName("freshList");
freshListAppender.start();

freshAsyncAppender.addAppender(freshListAppender);
freshAsyncAppender.start();
for (int i = 0; i < 10; i++) {
freshAsyncAppender.doAppend(i);
}

Assertions.assertEquals(10, freshAsyncAppender.getTotalAppendedCount());

freshAsyncAppender.resetMetrics();

Assertions.assertEquals(0, freshAsyncAppender.getTotalAppendedCount());
Assertions.assertEquals(0, freshAsyncAppender.getDiscardedByThresholdCount());
Assertions.assertEquals(0, freshAsyncAppender.getDiscardedByQueueFullCount());
Assertions.assertEquals(0, freshAsyncAppender.getTotalDiscardedCount());
Assertions.assertEquals(0, freshAsyncAppender.getDispatchedCount());
Assertions.assertEquals(0, freshAsyncAppender.getFailedDispatchCount());

freshAsyncAppender.stop();
}

@Test
@Timeout(value = 2, unit = TimeUnit.SECONDS)
public void metricsNoDiscardWhenQueueHasCapacity() {
asyncAppenderBase.addAppender(listAppender);
asyncAppenderBase.setQueueSize(100);
asyncAppenderBase.start();
int loopLen = 10;
for (int i = 0; i < loopLen; i++) {
asyncAppenderBase.doAppend(i);
}
asyncAppenderBase.stop();

Assertions.assertEquals(loopLen, asyncAppenderBase.getTotalAppendedCount());
Assertions.assertEquals(0, asyncAppenderBase.getTotalDiscardedCount());
verify(listAppender, loopLen);
}

@Test
@Timeout(value = 2, unit = TimeUnit.SECONDS)
public void metricsDispatchedCount() {
asyncAppenderBase.addAppender(listAppender);
asyncAppenderBase.start();
int loopLen = 10;
for (int i = 0; i < loopLen; i++) {
asyncAppenderBase.doAppend(i);
}
asyncAppenderBase.stop();

// All events should be dispatched (none discarded)
Assertions.assertEquals(loopLen, asyncAppenderBase.getTotalAppendedCount());
Assertions.assertEquals(loopLen, asyncAppenderBase.getDispatchedCount());
Assertions.assertEquals(0, asyncAppenderBase.getTotalDiscardedCount());

// Verify consistency: appended = dispatched + discarded + in-flight
// After stop(), in-flight should be 0
Assertions.assertEquals(asyncAppenderBase.getTotalAppendedCount(),
asyncAppenderBase.getDispatchedCount() + asyncAppenderBase.getTotalDiscardedCount());
}

@Test
@Timeout(value = 2, unit = TimeUnit.SECONDS)
public void metricsFailedDispatchCount() {
// Use NPEAppender which throws exceptions
NPEAppender<Integer> npeAppender = new NPEAppender<>();
npeAppender.setName("bad");
npeAppender.setContext(context);
npeAppender.start();

asyncAppenderBase.addAppender(npeAppender);
asyncAppenderBase.start();

int loopLen = 5;
for (int i = 0; i < loopLen; i++) {
asyncAppenderBase.doAppend(i);
}
asyncAppenderBase.stop();

// All events should have been appended
Assertions.assertEquals(loopLen, asyncAppenderBase.getTotalAppendedCount());

// No events discarded
Assertions.assertEquals(0, asyncAppenderBase.getTotalDiscardedCount());

// NPEAppender catches exceptions in AppenderBase.doAppend, so they don't
// propagate to our counter. This test verifies the counter exists and works.
// In real scenarios, uncaught exceptions from non-standard appenders would
// be counted here.
Assertions.assertEquals(0, asyncAppenderBase.getFailedDispatchCount());
}
}