From baf8bd59a1944c158a41d133376c01cfbe2d27ed Mon Sep 17 00:00:00 2001 From: Alexander Dinauer Date: Tue, 13 Dec 2022 08:06:11 +0100 Subject: [PATCH 1/7] Add tests for linking errors to otel transactions --- .../OpenTelemetryLinkErrorEventProcessor.java | 14 +++++- .../test/kotlin/SentrySpanProcessorTest.kt | 47 +++++++++++++++++++ 2 files changed, 60 insertions(+), 1 deletion(-) diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java index f01d9ec3ed..e528afe2e4 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java @@ -6,6 +6,7 @@ import io.sentry.EventProcessor; import io.sentry.Hint; import io.sentry.HubAdapter; +import io.sentry.IHub; import io.sentry.ISpan; import io.sentry.Instrumenter; import io.sentry.SentryEvent; @@ -14,14 +15,25 @@ import io.sentry.protocol.SentryId; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; +import org.jetbrains.annotations.TestOnly; public final class OpenTelemetryLinkErrorEventProcessor implements EventProcessor { + private final @NotNull IHub hub; private final @NotNull SentrySpanStorage spanStorage = SentrySpanStorage.getInstance(); + public OpenTelemetryLinkErrorEventProcessor() { + this(HubAdapter.getInstance()); + } + + @TestOnly + OpenTelemetryLinkErrorEventProcessor(final @NotNull IHub hub) { + this.hub = hub; + } + @Override public @Nullable SentryEvent process(final @NotNull SentryEvent event, final @NotNull Hint hint) { - if (Instrumenter.OTEL.equals(HubAdapter.getInstance().getOptions().getInstrumenter())) { + if (Instrumenter.OTEL.equals(hub.getOptions().getInstrumenter())) { @NotNull final Span otelSpan = Span.current(); @NotNull final String traceId = otelSpan.getSpanContext().getTraceId(); @NotNull final String spanId = otelSpan.getSpanContext().getSpanId(); diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt b/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt index 4c3df4b72b..0c6fe77f26 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt @@ -20,10 +20,12 @@ import io.opentelemetry.sdk.trace.SdkTracerProvider import io.opentelemetry.semconv.trace.attributes.SemanticAttributes import io.sentry.Baggage import io.sentry.BaggageHeader +import io.sentry.Hint import io.sentry.IHub import io.sentry.ISpan import io.sentry.ITransaction import io.sentry.Instrumenter +import io.sentry.SentryEvent import io.sentry.SentryOptions import io.sentry.SentryTraceHeader import io.sentry.SpanStatus @@ -66,6 +68,7 @@ class SentrySpanProcessorTest { val hub = mock() val transaction = mock() val span = mock() + val spanContext = mock() lateinit var openTelemetry: OpenTelemetry lateinit var tracer: Tracer val sentryTrace = SentryTraceHeader(SENTRY_TRACE_HEADER_STRING) @@ -76,6 +79,11 @@ class SentrySpanProcessorTest { whenever(hub.options).thenReturn(options) whenever(hub.startTransaction(any(), any())).thenReturn(transaction) + whenever(spanContext.operation).thenReturn("spanContextOp") + whenever(spanContext.parentSpanId).thenReturn(io.sentry.SpanId("cedf5b7571cb4972")) + + whenever(transaction.spanContext).thenReturn(spanContext) + whenever(span.spanContext).thenReturn(spanContext) whenever(span.toSentryTrace()).thenReturn(sentryTrace) whenever(transaction.toSentryTrace()).thenReturn(sentryTrace) @@ -322,6 +330,40 @@ class SentrySpanProcessorTest { thenTransactionIsFinished() } + @Test + fun `links error to OTEL transaction`() { + fixture.setup() + val extractedContext = whenExtractingHeaders() + + extractedContext.makeCurrent().use { _ -> + val otelSpan = givenSpanBuilder().startSpan() + thenTransactionIsStarted(otelSpan, isContinued = true) + + otelSpan.makeCurrent().use { _ -> + val processedEvent = OpenTelemetryLinkErrorEventProcessor(fixture.hub).process(SentryEvent(), Hint()) + val traceContext = processedEvent!!.contexts.trace!! + + assertEquals("2722d9f6ec019ade60c776169d9a8904", traceContext.traceId.toString()) + assertEquals(otelSpan.spanContext.spanId, traceContext.spanId.toString()) + assertEquals("cedf5b7571cb4972", traceContext.parentSpanId.toString()) + assertEquals("spanContextOp", traceContext.operation) + } + + otelSpan.end() + thenTransactionIsFinished() + } + } + + @Test + fun `does not link error to OTEL transaction if instrumenter does not match`() { + fixture.options.instrumenter = Instrumenter.SENTRY + fixture.setup() + + val processedEvent = OpenTelemetryLinkErrorEventProcessor(fixture.hub).process(SentryEvent(), Hint()) + + thenNoTraceContextHasBeenAddedToEvent(processedEvent) + } + private fun givenSpanBuilder(spanKind: SpanKind = SpanKind.SERVER, parentSpan: Span? = null): SpanBuilder { val spanName = if (parentSpan == null) "testspan" else "childspan" val spanBuilder = fixture.tracer @@ -430,6 +472,11 @@ class SentrySpanProcessorTest { verify(fixture.transaction).setContext(eq("otel"), any()) verify(fixture.transaction).finish(eq(SpanStatus.OK), any()) } + + private fun thenNoTraceContextHasBeenAddedToEvent(event: SentryEvent?) { + assertNotNull(event) + assertNull(event.contexts.trace) + } } class HeaderGetter : TextMapGetter { From 49efc4cf3a5eea830e9c5a4849779b4f1b7fdf50 Mon Sep 17 00:00:00 2001 From: Alexander Dinauer Date: Tue, 13 Dec 2022 10:14:25 +0100 Subject: [PATCH 2/7] Add logging to OTEL code --- .../OpenTelemetryLinkErrorEventProcessor.java | 29 ++++++++- .../opentelemetry/SentryPropagator.java | 32 ++++++++++ .../opentelemetry/SentrySpanProcessor.java | 63 ++++++++++++++++++- .../test/kotlin/SentrySpanProcessorTest.kt | 22 ++++--- 4 files changed, 133 insertions(+), 13 deletions(-) diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java index e528afe2e4..bec48e0fc7 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java @@ -10,6 +10,7 @@ import io.sentry.ISpan; import io.sentry.Instrumenter; import io.sentry.SentryEvent; +import io.sentry.SentryLevel; import io.sentry.SentrySpanStorage; import io.sentry.SpanContext; import io.sentry.protocol.SentryId; @@ -33,7 +34,8 @@ public OpenTelemetryLinkErrorEventProcessor() { @Override public @Nullable SentryEvent process(final @NotNull SentryEvent event, final @NotNull Hint hint) { - if (Instrumenter.OTEL.equals(hub.getOptions().getInstrumenter())) { + final @NotNull Instrumenter instrumenter = hub.getOptions().getInstrumenter(); + if (Instrumenter.OTEL.equals(instrumenter)) { @NotNull final Span otelSpan = Span.current(); @NotNull final String traceId = otelSpan.getSpanContext().getTraceId(); @NotNull final String spanId = otelSpan.getSpanContext().getSpanId(); @@ -53,8 +55,33 @@ public OpenTelemetryLinkErrorEventProcessor() { null); event.getContexts().setTrace(spanContext); + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Linking Sentry event to span %s created via OpenTelemetry.", + spanId); + } else { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not linking Sentry event to any transaction created via OpenTelemetry as none has been found."); } + } else { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not linking Sentry event to any transaction created via OpenTelemetry as traceId or spanId are invalid."); } + } else { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not linking Sentry event to any transaction created via OpenTelemetry as instrumenter is set to %s.", + instrumenter); } return event; diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java index f82f747c85..4ca85dd572 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java @@ -10,7 +10,10 @@ import io.opentelemetry.context.propagation.TextMapSetter; import io.sentry.Baggage; import io.sentry.BaggageHeader; +import io.sentry.HubAdapter; +import io.sentry.IHub; import io.sentry.ISpan; +import io.sentry.SentryLevel; import io.sentry.SentrySpanStorage; import io.sentry.SentryTraceHeader; import io.sentry.exception.InvalidSentryTraceHeaderException; @@ -26,6 +29,15 @@ public final class SentryPropagator implements TextMapPropagator { private static final @NotNull List FIELDS = Arrays.asList(SentryTraceHeader.SENTRY_TRACE_HEADER, BaggageHeader.BAGGAGE_HEADER); private final @NotNull SentrySpanStorage spanStorage = SentrySpanStorage.getInstance(); + private final @NotNull IHub hub; + + public SentryPropagator() { + this(HubAdapter.getInstance()); + } + + SentryPropagator(final @NotNull IHub hub) { + this.hub = hub; + } @Override public Collection fields() { @@ -37,10 +49,20 @@ public void inject(final Context context, final C carrier, final TextMapSett final @NotNull Span otelSpan = Span.fromContext(context); final @NotNull SpanContext otelSpanContext = otelSpan.getSpanContext(); if (!otelSpanContext.isValid()) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not injecting Sentry tracing information for invalid OpenTelemetry span."); return; } final @Nullable ISpan sentrySpan = spanStorage.get(otelSpanContext.getSpanId()); if (sentrySpan == null || sentrySpan.isNoOp()) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not injecting Sentry tracing information as no Sentry span has been found or it is a NoOp."); return; } @@ -82,8 +104,18 @@ public Context extract( Span wrappedSpan = Span.wrap(otelSpanContext); modifiedContext = modifiedContext.with(wrappedSpan); + hub.getOptions() + .getLogger() + .log(SentryLevel.DEBUG, "Continuing Sentry trace %s", sentryTraceHeader.getTraceId()); + return modifiedContext; } catch (InvalidSentryTraceHeaderException e) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.ERROR, + "Unable to extract Sentry tracing information from invalid header.", + e); return context; } } diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java index fba597a48c..c02a073f17 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java @@ -19,6 +19,7 @@ import io.sentry.ISpan; import io.sentry.ITransaction; import io.sentry.Instrumenter; +import io.sentry.SentryLevel; import io.sentry.SentrySpanStorage; import io.sentry.SentryTraceHeader; import io.sentry.SpanId; @@ -48,7 +49,7 @@ public SentrySpanProcessor() { this(HubAdapter.getInstance()); } - SentrySpanProcessor(@NotNull IHub hub) { + SentrySpanProcessor(final @NotNull IHub hub) { this.hub = hub; } @@ -59,6 +60,11 @@ public void onStart(final @NotNull Context parentContext, final @NotNull ReadWri } if (isSentryRequest(otelSpan)) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not forwarding OpenTelemetry Span to Sentry as this looks like a span for a request to Sentry."); return; } @@ -67,6 +73,13 @@ public void onStart(final @NotNull Context parentContext, final @NotNull ReadWri traceData.getParentSpanId() == null ? null : spanStorage.get(traceData.getParentSpanId()); if (sentryParentSpan != null) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Creating Sentry child span %s for OpenTelemetry span. Parent span is %s.", + traceData.getSpanId(), + traceData.getParentSpanId()); final @NotNull Date startDate = DateUtils.nanosToDate(otelSpan.toSpanData().getStartEpochNanos()); final @NotNull ISpan sentryChildSpan = @@ -74,6 +87,12 @@ public void onStart(final @NotNull Context parentContext, final @NotNull ReadWri otelSpan.getName(), otelSpan.getName(), startDate, Instrumenter.OTEL); spanStorage.store(traceData.getSpanId(), sentryChildSpan); } else { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Creating Sentry transaction %s for OpenTelemetry span.", + traceData.getSpanId()); final @NotNull String transactionName = otelSpan.getName(); final @NotNull TransactionNameSource transactionNameSource = TransactionNameSource.CUSTOM; final @Nullable String op = otelSpan.getName(); @@ -124,18 +143,41 @@ public void onEnd(final @NotNull ReadableSpan otelSpan) { final @Nullable ISpan sentrySpan = spanStorage.removeAndGet(traceData.getSpanId()); if (sentrySpan == null) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Unable to find Sentry span for OpenTelemetry span %s.", + traceData.getSpanId()); return; } if (isSentryRequest(otelSpan)) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not forwarding OpenTelemetry Span to Sentry as this looks like a span for a request to Sentry."); return; } if (sentrySpan instanceof ITransaction) { ITransaction sentryTransaction = (ITransaction) sentrySpan; updateTransactionWithOtelData(sentryTransaction, otelSpan); + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Finishing Sentry transaction for OpenTelemetry span %s.", + traceData.getSpanId()); } else { updateSpanWithOtelData(sentrySpan, otelSpan); + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Finishing Sentry span for OpenTelemetry span %s.", + traceData.getSpanId()); } final @NotNull SpanStatus sentryStatus = mapOtelStatus(otelSpan); @@ -151,15 +193,32 @@ public boolean isEndRequired() { private boolean ensurePrerequisites(final @NotNull ReadableSpan otelSpan) { if (!hasSentryBeenInitialized()) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not forwarding OpenTelemetry Span to Sentry as Sentry has not yet been initialized."); return false; } - if (!Instrumenter.OTEL.equals(hub.getOptions().getInstrumenter())) { + final @NotNull Instrumenter instrumenter = hub.getOptions().getInstrumenter(); + if (!Instrumenter.OTEL.equals(instrumenter)) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not forwarding OpenTelemetry Span to Sentry as instrumenter has been set to %s.", + instrumenter); return false; } final @NotNull SpanContext otelSpanContext = otelSpan.getSpanContext(); if (!otelSpanContext.isValid()) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.DEBUG, + "Not forwarding OpenTelemetry Span to Sentry as the span is invalid."); return false; } diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt b/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt index 0c6fe77f26..472cf17f2a 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/test/kotlin/SentrySpanProcessorTest.kt @@ -142,30 +142,32 @@ class SentrySpanProcessorTest { @Test fun `does nothing on start if Sentry has not been initialized`() { - val hub = mock() + fixture.setup() val context = mock() val span = mock() - whenever(hub.isEnabled).thenReturn(false) + whenever(fixture.hub.isEnabled).thenReturn(false) - SentrySpanProcessor(hub).onStart(context, span) + SentrySpanProcessor(fixture.hub).onStart(context, span) - verify(hub).isEnabled - verifyNoMoreInteractions(hub) + verify(fixture.hub).isEnabled + verify(fixture.hub).options + verifyNoMoreInteractions(fixture.hub) verifyNoInteractions(context, span) } @Test fun `does nothing on end if Sentry has not been initialized`() { - val hub = mock() + fixture.setup() val span = mock() - whenever(hub.isEnabled).thenReturn(false) + whenever(fixture.hub.isEnabled).thenReturn(false) - SentrySpanProcessor(hub).onEnd(span) + SentrySpanProcessor(fixture.hub).onEnd(span) - verify(hub).isEnabled - verifyNoMoreInteractions(hub) + verify(fixture.hub).isEnabled + verify(fixture.hub).options + verifyNoMoreInteractions(fixture.hub) verifyNoInteractions(span) } From 183423a7867e1152f6b7b4715182f01670ccd220 Mon Sep 17 00:00:00 2001 From: Alexander Dinauer Date: Tue, 13 Dec 2022 13:16:09 +0100 Subject: [PATCH 3/7] Add more IDs to log statements --- .../OpenTelemetryLinkErrorEventProcessor.java | 19 +++++--- .../opentelemetry/SentryPropagator.java | 4 +- .../opentelemetry/SentrySpanProcessor.java | 45 ++++++++++++------- 3 files changed, 45 insertions(+), 23 deletions(-) diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java index bec48e0fc7..1e373ece9c 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/OpenTelemetryLinkErrorEventProcessor.java @@ -59,28 +59,37 @@ public OpenTelemetryLinkErrorEventProcessor() { .getLogger() .log( SentryLevel.DEBUG, - "Linking Sentry event to span %s created via OpenTelemetry.", - spanId); + "Linking Sentry event %s to span %s created via OpenTelemetry (trace %s).", + event.getEventId(), + spanId, + traceId); } else { hub.getOptions() .getLogger() .log( SentryLevel.DEBUG, - "Not linking Sentry event to any transaction created via OpenTelemetry as none has been found."); + "Not linking Sentry event %s to any transaction created via OpenTelemetry as none has been found for span %s (trace %s).", + event.getEventId(), + spanId, + traceId); } } else { hub.getOptions() .getLogger() .log( SentryLevel.DEBUG, - "Not linking Sentry event to any transaction created via OpenTelemetry as traceId or spanId are invalid."); + "Not linking Sentry event %s to any transaction created via OpenTelemetry as traceId %s or spanId %s are invalid.", + event.getEventId(), + traceId, + spanId); } } else { hub.getOptions() .getLogger() .log( SentryLevel.DEBUG, - "Not linking Sentry event to any transaction created via OpenTelemetry as instrumenter is set to %s.", + "Not linking Sentry event %s to any transaction created via OpenTelemetry as instrumenter is set to %s.", + event.getEventId(), instrumenter); } diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java index 4ca85dd572..14ac12323b 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentryPropagator.java @@ -62,7 +62,9 @@ public void inject(final Context context, final C carrier, final TextMapSett .getLogger() .log( SentryLevel.DEBUG, - "Not injecting Sentry tracing information as no Sentry span has been found or it is a NoOp."); + "Not injecting Sentry tracing information for span %s as no Sentry span has been found or it is a NoOp (trace %s). This might simply mean this is a request to Sentry.", + otelSpanContext.getSpanId(), + otelSpanContext.getTraceId()); return; } diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java index c02a073f17..3a31269109 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java @@ -59,16 +59,18 @@ public void onStart(final @NotNull Context parentContext, final @NotNull ReadWri return; } + final @NotNull TraceData traceData = getTraceData(otelSpan, parentContext); + if (isSentryRequest(otelSpan)) { hub.getOptions() .getLogger() .log( SentryLevel.DEBUG, - "Not forwarding OpenTelemetry Span to Sentry as this looks like a span for a request to Sentry."); + "Not forwarding OpenTelemetry span %s to Sentry as this looks like a span for a request to Sentry (trace %s).", + traceData.getSpanId(), + traceData.getTraceId()); return; } - - final @NotNull TraceData traceData = getTraceData(otelSpan, parentContext); final @Nullable ISpan sentryParentSpan = traceData.getParentSpanId() == null ? null : spanStorage.get(traceData.getParentSpanId()); @@ -77,8 +79,9 @@ public void onStart(final @NotNull Context parentContext, final @NotNull ReadWri .getLogger() .log( SentryLevel.DEBUG, - "Creating Sentry child span %s for OpenTelemetry span. Parent span is %s.", + "Creating Sentry child span for OpenTelemetry span %s (trace %s). Parent span is %s.", traceData.getSpanId(), + traceData.getTraceId(), traceData.getParentSpanId()); final @NotNull Date startDate = DateUtils.nanosToDate(otelSpan.toSpanData().getStartEpochNanos()); @@ -91,8 +94,9 @@ public void onStart(final @NotNull Context parentContext, final @NotNull ReadWri .getLogger() .log( SentryLevel.DEBUG, - "Creating Sentry transaction %s for OpenTelemetry span.", - traceData.getSpanId()); + "Creating Sentry transaction for OpenTelemetry span %s (trace %s).", + traceData.getSpanId(), + traceData.getTraceId()); final @NotNull String transactionName = otelSpan.getName(); final @NotNull TransactionNameSource transactionNameSource = TransactionNameSource.CUSTOM; final @Nullable String op = otelSpan.getName(); @@ -147,8 +151,9 @@ public void onEnd(final @NotNull ReadableSpan otelSpan) { .getLogger() .log( SentryLevel.DEBUG, - "Unable to find Sentry span for OpenTelemetry span %s.", - traceData.getSpanId()); + "Unable to find Sentry span for OpenTelemetry span %s (trace %s).", + traceData.getSpanId(), + traceData.getTraceId()); return; } @@ -157,27 +162,33 @@ public void onEnd(final @NotNull ReadableSpan otelSpan) { .getLogger() .log( SentryLevel.DEBUG, - "Not forwarding OpenTelemetry Span to Sentry as this looks like a span for a request to Sentry."); + "Not forwarding OpenTelemetry span %s to Sentry as this looks like a span for a request to Sentry (trace %s).", + traceData.getSpanId(), + traceData.getTraceId()); return; } if (sentrySpan instanceof ITransaction) { - ITransaction sentryTransaction = (ITransaction) sentrySpan; + final @NotNull ITransaction sentryTransaction = (ITransaction) sentrySpan; updateTransactionWithOtelData(sentryTransaction, otelSpan); hub.getOptions() .getLogger() .log( SentryLevel.DEBUG, - "Finishing Sentry transaction for OpenTelemetry span %s.", - traceData.getSpanId()); + "Finishing Sentry transaction %s for OpenTelemetry span %s (trace %s).", + sentryTransaction.getEventId(), + traceData.getSpanId(), + traceData.getTraceId()); } else { updateSpanWithOtelData(sentrySpan, otelSpan); hub.getOptions() .getLogger() .log( SentryLevel.DEBUG, - "Finishing Sentry span for OpenTelemetry span %s.", - traceData.getSpanId()); + "Finishing Sentry span for OpenTelemetry span %s (trace %s). Parent span is %s.", + traceData.getSpanId(), + traceData.getTraceId(), + traceData.getParentSpanId()); } final @NotNull SpanStatus sentryStatus = mapOtelStatus(otelSpan); @@ -197,7 +208,7 @@ private boolean ensurePrerequisites(final @NotNull ReadableSpan otelSpan) { .getLogger() .log( SentryLevel.DEBUG, - "Not forwarding OpenTelemetry Span to Sentry as Sentry has not yet been initialized."); + "Not forwarding OpenTelemetry span to Sentry as Sentry has not yet been initialized."); return false; } @@ -207,7 +218,7 @@ private boolean ensurePrerequisites(final @NotNull ReadableSpan otelSpan) { .getLogger() .log( SentryLevel.DEBUG, - "Not forwarding OpenTelemetry Span to Sentry as instrumenter has been set to %s.", + "Not forwarding OpenTelemetry span to Sentry as instrumenter has been set to %s.", instrumenter); return false; } @@ -218,7 +229,7 @@ private boolean ensurePrerequisites(final @NotNull ReadableSpan otelSpan) { .getLogger() .log( SentryLevel.DEBUG, - "Not forwarding OpenTelemetry Span to Sentry as the span is invalid."); + "Not forwarding OpenTelemetry span to Sentry as the span is invalid."); return false; } From 8b47a99a9a7b80e22cce2c8809112263fa881c76 Mon Sep 17 00:00:00 2001 From: Alexander Dinauer Date: Tue, 13 Dec 2022 13:20:52 +0100 Subject: [PATCH 4/7] Add changelog --- CHANGELOG.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index f24e050621..1639c3d3b2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,10 @@ ## Unreleased +### Features + +- Add logging for OpenTelemetry integration ([#2425](https://github.com/getsentry/sentry-java/pull/2425)) + ### Dependencies - Bump Native SDK from v0.5.2 to v0.5.3 ([#2423](https://github.com/getsentry/sentry-java/pull/2423)) From e3c8470569777b44d4828e48e3a096ffbbd9589b Mon Sep 17 00:00:00 2001 From: Alexander Dinauer Date: Thu, 15 Dec 2022 12:36:31 +0100 Subject: [PATCH 5/7] Auto add OpenTelemetryLinkErrorEventProcessor for Spring Boot --- .../build.gradle.kts | 2 + .../boot/jakarta/SentryAutoConfiguration.java | 14 +++++++ .../jakarta/SentryAutoConfigurationTest.kt | 42 +++++++++++++++++++ sentry-spring-boot-starter/build.gradle.kts | 2 + .../spring/boot/SentryAutoConfiguration.java | 14 +++++++ .../boot/SentryAutoConfigurationTest.kt | 42 +++++++++++++++++++ 6 files changed, 116 insertions(+) diff --git a/sentry-spring-boot-starter-jakarta/build.gradle.kts b/sentry-spring-boot-starter-jakarta/build.gradle.kts index 34d3e51bf3..5279f3080f 100644 --- a/sentry-spring-boot-starter-jakarta/build.gradle.kts +++ b/sentry-spring-boot-starter-jakarta/build.gradle.kts @@ -53,6 +53,7 @@ dependencies { compileOnly(Config.Libs.springBoot3StarterAop) compileOnly(Config.Libs.springBoot3StarterSecurity) compileOnly(Config.Libs.reactorCore) + compileOnly(projects.sentryOpentelemetry.sentryOpentelemetryCore) annotationProcessor(Config.AnnotationProcessors.springBootAutoConfigure) annotationProcessor(Config.AnnotationProcessors.springBootConfiguration) @@ -77,6 +78,7 @@ dependencies { testImplementation(Config.Libs.springBoot3StarterWebflux) testImplementation(Config.Libs.springBoot3StarterSecurity) testImplementation(Config.Libs.springBoot3StarterAop) + testImplementation(projects.sentryOpentelemetry.sentryOpentelemetryCore) } configure { diff --git a/sentry-spring-boot-starter-jakarta/src/main/java/io/sentry/spring/boot/jakarta/SentryAutoConfiguration.java b/sentry-spring-boot-starter-jakarta/src/main/java/io/sentry/spring/boot/jakarta/SentryAutoConfiguration.java index a8daf9d531..741e8bb135 100644 --- a/sentry-spring-boot-starter-jakarta/src/main/java/io/sentry/spring/boot/jakarta/SentryAutoConfiguration.java +++ b/sentry-spring-boot-starter-jakarta/src/main/java/io/sentry/spring/boot/jakarta/SentryAutoConfiguration.java @@ -8,6 +8,7 @@ import io.sentry.Integration; import io.sentry.Sentry; import io.sentry.SentryOptions; +import io.sentry.opentelemetry.OpenTelemetryLinkErrorEventProcessor; import io.sentry.protocol.SdkVersion; import io.sentry.spring.jakarta.ContextTagsEventProcessor; import io.sentry.spring.jakarta.SentryExceptionResolver; @@ -138,6 +139,19 @@ static class ContextTagsEventProcessorConfiguration { } } + @Configuration(proxyBeanMethods = false) + @ConditionalOnProperty(name = "sentry.auto-init", havingValue = "false") + @ConditionalOnClass(OpenTelemetryLinkErrorEventProcessor.class) + @Open + static class OpenTelemetryLinkErrorEventProcessorConfiguration { + + @Bean + @ConditionalOnMissingBean + public @NotNull OpenTelemetryLinkErrorEventProcessor openTelemetryLinkErrorEventProcessor() { + return new OpenTelemetryLinkErrorEventProcessor(); + } + } + /** Registers beans specific to Spring MVC. */ @Configuration(proxyBeanMethods = false) @ConditionalOnWebApplication(type = ConditionalOnWebApplication.Type.SERVLET) diff --git a/sentry-spring-boot-starter-jakarta/src/test/kotlin/io/sentry/spring/boot/jakarta/SentryAutoConfigurationTest.kt b/sentry-spring-boot-starter-jakarta/src/test/kotlin/io/sentry/spring/boot/jakarta/SentryAutoConfigurationTest.kt index ba6abeaa7e..c972e316cb 100644 --- a/sentry-spring-boot-starter-jakarta/src/test/kotlin/io/sentry/spring/boot/jakarta/SentryAutoConfigurationTest.kt +++ b/sentry-spring-boot-starter-jakarta/src/test/kotlin/io/sentry/spring/boot/jakarta/SentryAutoConfigurationTest.kt @@ -15,6 +15,7 @@ import io.sentry.SentryEvent import io.sentry.SentryLevel import io.sentry.SentryOptions import io.sentry.checkEvent +import io.sentry.opentelemetry.OpenTelemetryLinkErrorEventProcessor import io.sentry.protocol.SentryTransaction import io.sentry.protocol.User import io.sentry.spring.jakarta.ContextTagsEventProcessor @@ -683,6 +684,47 @@ class SentryAutoConfigurationTest { } } + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is on the classpath and auto init off, creates OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj", "sentry.auto-init=false") + .run { + assertThat(it).hasSingleBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).anyMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is on the classpath but auto init on, does not create OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj", "sentry.auto-init=true") + .run { + assertThat(it).doesNotHaveBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).noneMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is on the classpath but auto init default, does not create OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj") + .run { + assertThat(it).doesNotHaveBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).noneMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is not on the classpath, does not create OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj", "sentry.auto-init=false") + .withClassLoader(FilteredClassLoader(OpenTelemetryLinkErrorEventProcessor::class.java)) + .run { + assertThat(it).doesNotHaveBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).noneMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + @Configuration(proxyBeanMethods = false) open class CustomOptionsConfigurationConfiguration { diff --git a/sentry-spring-boot-starter/build.gradle.kts b/sentry-spring-boot-starter/build.gradle.kts index bca7c8daa6..19f2a43a2d 100644 --- a/sentry-spring-boot-starter/build.gradle.kts +++ b/sentry-spring-boot-starter/build.gradle.kts @@ -43,6 +43,7 @@ dependencies { compileOnly(Config.Libs.springBootStarterAop) compileOnly(Config.Libs.springBootStarterSecurity) compileOnly(Config.Libs.reactorCore) + compileOnly(projects.sentryOpentelemetry.sentryOpentelemetryCore) annotationProcessor(Config.AnnotationProcessors.springBootAutoConfigure) annotationProcessor(Config.AnnotationProcessors.springBootConfiguration) @@ -67,6 +68,7 @@ dependencies { testImplementation(Config.Libs.springBootStarterWebflux) testImplementation(Config.Libs.springBootStarterSecurity) testImplementation(Config.Libs.springBootStarterAop) + testImplementation(projects.sentryOpentelemetry.sentryOpentelemetryCore) } configure { diff --git a/sentry-spring-boot-starter/src/main/java/io/sentry/spring/boot/SentryAutoConfiguration.java b/sentry-spring-boot-starter/src/main/java/io/sentry/spring/boot/SentryAutoConfiguration.java index 908d73c063..cb33c48c37 100644 --- a/sentry-spring-boot-starter/src/main/java/io/sentry/spring/boot/SentryAutoConfiguration.java +++ b/sentry-spring-boot-starter/src/main/java/io/sentry/spring/boot/SentryAutoConfiguration.java @@ -8,6 +8,7 @@ import io.sentry.Integration; import io.sentry.Sentry; import io.sentry.SentryOptions; +import io.sentry.opentelemetry.OpenTelemetryLinkErrorEventProcessor; import io.sentry.protocol.SdkVersion; import io.sentry.spring.ContextTagsEventProcessor; import io.sentry.spring.SentryExceptionResolver; @@ -139,6 +140,19 @@ static class ContextTagsEventProcessorConfiguration { } } + @Configuration(proxyBeanMethods = false) + @ConditionalOnProperty(name = "sentry.auto-init", havingValue = "false") + @ConditionalOnClass(OpenTelemetryLinkErrorEventProcessor.class) + @Open + static class OpenTelemetryLinkErrorEventProcessorConfiguration { + + @Bean + @ConditionalOnMissingBean + public @NotNull OpenTelemetryLinkErrorEventProcessor openTelemetryLinkErrorEventProcessor() { + return new OpenTelemetryLinkErrorEventProcessor(); + } + } + /** Registers beans specific to Spring MVC. */ @Configuration(proxyBeanMethods = false) @ConditionalOnWebApplication(type = ConditionalOnWebApplication.Type.SERVLET) diff --git a/sentry-spring-boot-starter/src/test/kotlin/io/sentry/spring/boot/SentryAutoConfigurationTest.kt b/sentry-spring-boot-starter/src/test/kotlin/io/sentry/spring/boot/SentryAutoConfigurationTest.kt index b8ede6e995..cff7f96d0d 100644 --- a/sentry-spring-boot-starter/src/test/kotlin/io/sentry/spring/boot/SentryAutoConfigurationTest.kt +++ b/sentry-spring-boot-starter/src/test/kotlin/io/sentry/spring/boot/SentryAutoConfigurationTest.kt @@ -15,6 +15,7 @@ import io.sentry.SentryEvent import io.sentry.SentryLevel import io.sentry.SentryOptions import io.sentry.checkEvent +import io.sentry.opentelemetry.OpenTelemetryLinkErrorEventProcessor import io.sentry.protocol.SentryTransaction import io.sentry.protocol.User import io.sentry.spring.ContextTagsEventProcessor @@ -683,6 +684,47 @@ class SentryAutoConfigurationTest { } } + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is on the classpath and auto init off, creates OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj", "sentry.auto-init=false") + .run { + assertThat(it).hasSingleBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).anyMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is on the classpath but auto init on, does not create OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj", "sentry.auto-init=true") + .run { + assertThat(it).doesNotHaveBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).noneMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is on the classpath but auto init default, does not create OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj") + .run { + assertThat(it).doesNotHaveBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).noneMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + + @Test + fun `when OpenTelemetryLinkErrorEventProcessor is not on the classpath, does not create OpenTelemetryLinkErrorEventProcessor`() { + contextRunner.withPropertyValues("sentry.dsn=http://key@localhost/proj", "sentry.auto-init=false") + .withClassLoader(FilteredClassLoader(OpenTelemetryLinkErrorEventProcessor::class.java)) + .run { + assertThat(it).doesNotHaveBean(OpenTelemetryLinkErrorEventProcessor::class.java) + val options = it.getBean(SentryOptions::class.java) + assertThat(options.eventProcessors).noneMatch { processor -> processor.javaClass == OpenTelemetryLinkErrorEventProcessor::class.java } + } + } + @Configuration(proxyBeanMethods = false) open class CustomOptionsConfigurationConfiguration { From 707ea59a5c5abcded612c5b55585ce9df13fa536 Mon Sep 17 00:00:00 2001 From: Alexander Dinauer Date: Thu, 15 Dec 2022 12:46:02 +0100 Subject: [PATCH 6/7] Add changelog --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 1639c3d3b2..748f90826f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ ### Features - Add logging for OpenTelemetry integration ([#2425](https://github.com/getsentry/sentry-java/pull/2425)) +- Auto add `OpenTelemetryLinkErrorEventProcessor` for Spring Boot ([#2429](https://github.com/getsentry/sentry-java/pull/2429)) ### Dependencies From ba730c223ee7e111deb92121f884b7d76527db21 Mon Sep 17 00:00:00 2001 From: Alexander Dinauer Date: Mon, 19 Dec 2022 13:50:38 +0100 Subject: [PATCH 7/7] No longer require direct dependency on OTEL SDK in spring boot app when using agent --- .../sentry-opentelemetry-agentcustomization/build.gradle.kts | 5 ++++- .../sentry-opentelemetry-core/build.gradle.kts | 2 +- .../java/io/sentry/opentelemetry/SentrySpanProcessor.java | 2 +- 3 files changed, 6 insertions(+), 3 deletions(-) diff --git a/sentry-opentelemetry/sentry-opentelemetry-agentcustomization/build.gradle.kts b/sentry-opentelemetry/sentry-opentelemetry-agentcustomization/build.gradle.kts index a9b7f3666f..44528ac46f 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-agentcustomization/build.gradle.kts +++ b/sentry-opentelemetry/sentry-opentelemetry-agentcustomization/build.gradle.kts @@ -20,7 +20,10 @@ tasks.withType().configureEach { dependencies { compileOnly(projects.sentry) - implementation(projects.sentryOpentelemetry.sentryOpentelemetryCore) + implementation(projects.sentryOpentelemetry.sentryOpentelemetryCore) { + exclude(group = "io.opentelemetry") + exclude(group = "io.opentelemetry.javaagent") + } compileOnly(Config.Libs.OpenTelemetry.otelSdk) compileOnly(Config.Libs.OpenTelemetry.otelExtensionAutoconfigureSpi) diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/build.gradle.kts b/sentry-opentelemetry/sentry-opentelemetry-core/build.gradle.kts index c8db1650b2..621a8901c3 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/build.gradle.kts +++ b/sentry-opentelemetry/sentry-opentelemetry-core/build.gradle.kts @@ -21,7 +21,7 @@ tasks.withType().configureEach { dependencies { compileOnly(projects.sentry) - compileOnly(Config.Libs.OpenTelemetry.otelSdk) + implementation(Config.Libs.OpenTelemetry.otelSdk) compileOnly(Config.Libs.OpenTelemetry.otelSemconv) compileOnly(Config.CompileOnly.nopen) diff --git a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java index 3a31269109..7ecb732e88 100644 --- a/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java +++ b/sentry-opentelemetry/sentry-opentelemetry-core/src/main/java/io/sentry/opentelemetry/SentrySpanProcessor.java @@ -151,7 +151,7 @@ public void onEnd(final @NotNull ReadableSpan otelSpan) { .getLogger() .log( SentryLevel.DEBUG, - "Unable to find Sentry span for OpenTelemetry span %s (trace %s).", + "Unable to find Sentry span for OpenTelemetry span %s (trace %s). This may simply mean it is a Sentry request.", traceData.getSpanId(), traceData.getTraceId()); return;