Skip to content

Add rate‑limited log warning when BatchSpanProcessor drops spans #8167

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.

Sign up for GitHub

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

Open
VamshikrishnaMonagari wants to merge 1 commit into
base: main
Choose a base branch
from
+38 −0
Open

Add rate‑limited log warning when BatchSpanProcessor drops spans #8167

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
7 changes: 7 additions & 0 deletions sdk/trace/src/main/java/io/opentelemetry/sdk/trace/export/BatchSpanProcessor.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
import io.opentelemetry.sdk.common.InternalTelemetryVersion;
import io.opentelemetry.sdk.common.internal.ComponentId;
import io.opentelemetry.sdk.common.internal.DaemonThreadFactory;
import io.opentelemetry.sdk.common.internal.ThrottlingLogger;
import io.opentelemetry.sdk.common.internal.ThrowableUtil;
import io.opentelemetry.sdk.trace.ReadWriteSpan;
import io.opentelemetry.sdk.trace.ReadableSpan;
Expand Down Expand Up @@ -46,6 +47,7 @@ public final class BatchSpanProcessor implements SpanProcessor {
ComponentId.generateLazy("batching_span_processor");

private static final Logger logger = Logger.getLogger(BatchSpanProcessor.class.getName());
private static final ThrottlingLogger throttledLogger = new ThrottlingLogger(logger);

private static final String WORKER_THREAD_NAME =
BatchSpanProcessor.class.getSimpleName() + "_WorkerThread";
Expand Down Expand Up @@ -212,6 +214,11 @@ private void addSpan(ReadableSpan span) {
spanProcessorInstrumentation.buildQueueMetricsOnce(maxQueueSize, queue::size);
if (!queue.offer(span)) {
spanProcessorInstrumentation.dropSpans(1);
throttledLogger.log(
Level.WARNING,
"BatchSpanProcessor dropped a span because the queue is full (maxQueueSize="
+ maxQueueSize
+ ")");
} else {
if (queueSize.incrementAndGet() >= spansNeeded.get()) {
signal.offer(true);
Expand Down
31 changes: 31 additions & 0 deletions sdk/trace/src/test/java/io/opentelemetry/sdk/trace/export/BatchSpanProcessorTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
import io.opentelemetry.api.internal.GuardedBy;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.Tracer;
import io.github.netmikey.logunit.api.LogCapturer;
import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
import io.opentelemetry.sdk.common.CompletableResultCode;
import io.opentelemetry.sdk.trace.ReadableSpan;
Expand All @@ -29,6 +30,7 @@
import io.opentelemetry.sdk.trace.samplers.Sampler;
import io.opentelemetry.sdk.trace.samplers.SamplingResult;
import java.time.Duration;
import org.slf4j.event.Level;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
Expand All @@ -42,6 +44,7 @@
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.Timeout;
import org.junit.jupiter.api.extension.ExtendWith;
import org.junit.jupiter.api.extension.RegisterExtension;
import org.mockito.ArgumentMatchers;
import org.mockito.Mock;
import org.mockito.junit.jupiter.MockitoExtension;
Expand All @@ -62,9 +65,13 @@ class BatchSpanProcessorTest {
@Mock private Sampler mockSampler;
@Mock private SpanExporter mockSpanExporter;

@RegisterExtension
LogCapturer logs = LogCapturer.create().captureForType(BatchSpanProcessor.class);

@BeforeEach
void setUp() {
when(mockSpanExporter.shutdown()).thenReturn(CompletableResultCode.ofSuccess());
when(mockSpanExporter.export(anyList())).thenReturn(CompletableResultCode.ofSuccess());
}

@AfterEach
Expand Down Expand Up @@ -232,6 +239,30 @@ void exportMoreSpansThanTheBufferSize() {
span6.toSpanData()));
}

@Test
void droppedSpanIsLogged() {
sdkTracerProvider =
SdkTracerProvider.builder()
.addSpanProcessor(
BatchSpanProcessor.builder(mockSpanExporter)
.setMaxQueueSize(1)
.setMaxExportBatchSize(1_000)
.setScheduleDelay(Duration.ofDays(1))
.build())
.build();

// Add two spans quickly to trigger a drop when the queue is full.
createEndedSpan(SPAN_NAME_1);
createEndedSpan(SPAN_NAME_2);

await()
.untilAsserted(
() ->
logs.assertContains(
loggingEvent -> loggingEvent.getLevel().equals(Level.WARN),
"BatchSpanProcessor dropped a span"));
}

@Test
void forceExport() {
WaitingSpanExporter waitingSpanExporter =
Expand Down