-
Notifications
You must be signed in to change notification settings - Fork 952
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.
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
base: main
Are you sure you want to change the base?
Changes from all commits
ff11a8b
912e997
d14a2cc
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -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; | ||
|
|
@@ -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; | ||
|
|
@@ -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; | ||
|
|
@@ -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 | ||
|
|
@@ -232,6 +239,30 @@ void exportMoreSpansThanTheBufferSize() { | |
| span6.toSpanData())); | ||
| } | ||
|
|
||
| @Test | ||
| void droppedSpanIsLogged() { | ||
| sdkTracerProvider = | ||
| SdkTracerProvider.builder() | ||
| .addSpanProcessor( | ||
| BatchSpanProcessor.builder(mockSpanExporter) | ||
| .setMaxQueueSize(1) | ||
| .setMaxExportBatchSize(1) | ||
| .setScheduleDelay(Duration.ofMillis(1)) | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Since we don't need any exports, may as well set to a huge number to reduce potential flakiness. And maybe it makes sense then to drop more than one span |
||
| .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( | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Seems reasonable to assert the whole message, especially since it has some dynamic parts |
||
| loggingEvent -> loggingEvent.getLevel().equals(Level.WARN), | ||
| "BatchSpanProcessor dropped")); | ||
| } | ||
|
|
||
| @Test | ||
| void forceExport() { | ||
| WaitingSpanExporter waitingSpanExporter = | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@jack-berg do you think it would make sense to add something to the SpanProcessorInstrumentation to get this information, rather than tracking it separately here?
/cc @anuraaga
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Would have to maintain state over there but at least it would be hidden behind a central abstraction
An otel maximalist answer here would be:
I'm not trying to boil the ocean for this though 😛
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yeah if the
SpanProcessorInstrumentationwas already using an async counter or such with tracking, just reading that would be fine. But it's probably better to keep that synchronous (I think?) so keeping this BSP implementation detail in BSP seems to make more sense