diff --git a/CHANGELOG.md b/CHANGELOG.md index b88bf7718d..dd801cf04a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +- propagate okhttp status to parent spans ([#2872](https://github.com/getsentry/sentry-java/pull/2872)) + +### Fixes + ## 6.27.0 ### Features diff --git a/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEvent.kt b/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEvent.kt index 5727eb7a83..e96829e12e 100644 --- a/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEvent.kt +++ b/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEvent.kt @@ -63,7 +63,6 @@ internal class SentryOkHttpEvent(private val hub: IHub, private val request: Req breadcrumb.setData("status_code", response.code) callRootSpan?.setData(PROTOCOL_KEY, response.protocol.name) callRootSpan?.setData(SpanDataConvention.HTTP_STATUS_CODE_KEY, response.code) - callRootSpan?.status = SpanStatus.fromHttpStatusCode(response.code) } fun setProtocol(protocolName: String?) { @@ -98,24 +97,20 @@ internal class SentryOkHttpEvent(private val hub: IHub, private val request: Req /** Starts a span, if the callRootSpan is not null. */ fun startSpan(event: String) { // Find the parent of the span being created. E.g. secureConnect is child of connect - val parentSpan = when (event) { - // PROXY_SELECT, DNS, CONNECT and CONNECTION are not children of one another - SECURE_CONNECT_EVENT -> eventSpans[CONNECT_EVENT] - REQUEST_HEADERS_EVENT -> eventSpans[CONNECTION_EVENT] - REQUEST_BODY_EVENT -> eventSpans[CONNECTION_EVENT] - RESPONSE_HEADERS_EVENT -> eventSpans[CONNECTION_EVENT] - RESPONSE_BODY_EVENT -> eventSpans[CONNECTION_EVENT] - else -> callRootSpan - } ?: callRootSpan + val parentSpan = findParentSpan(event) val span = parentSpan?.startChild("http.client.$event") ?: return span.spanContext.origin = TRACE_ORIGIN eventSpans[event] = span } - /** Finishes a previously started span, and runs [beforeFinish] on it and on the call root span. */ + /** Finishes a previously started span, and runs [beforeFinish] on it, on its parent and on the call root span. */ fun finishSpan(event: String, beforeFinish: ((span: ISpan) -> Unit)? = null) { val span = eventSpans[event] ?: return + val parentSpan = findParentSpan(event) beforeFinish?.invoke(span) + if (parentSpan != null && parentSpan != callRootSpan) { + beforeFinish?.invoke(parentSpan) + } callRootSpan?.let { beforeFinish?.invoke(it) } span.finish() } @@ -125,7 +120,10 @@ internal class SentryOkHttpEvent(private val hub: IHub, private val request: Req callRootSpan ?: return // We forcefully finish all spans, even if they should already have been finished through finishSpan() - eventSpans.values.filter { !it.isFinished }.forEach { it.finish(SpanStatus.DEADLINE_EXCEEDED) } + eventSpans.values.filter { !it.isFinished }.forEach { + // If a status was set on the span, we use that, otherwise we set its status as error. + it.finish(it.status ?: SpanStatus.INTERNAL_ERROR) + } beforeFinish?.invoke(callRootSpan) callRootSpan.finish() @@ -137,4 +135,14 @@ internal class SentryOkHttpEvent(private val hub: IHub, private val request: Req hub.addBreadcrumb(breadcrumb, hint) return } + + private fun findParentSpan(event: String): ISpan? = when (event) { + // PROXY_SELECT, DNS, CONNECT and CONNECTION are not children of one another + SECURE_CONNECT_EVENT -> eventSpans[CONNECT_EVENT] + REQUEST_HEADERS_EVENT -> eventSpans[CONNECTION_EVENT] + REQUEST_BODY_EVENT -> eventSpans[CONNECTION_EVENT] + RESPONSE_HEADERS_EVENT -> eventSpans[CONNECTION_EVENT] + RESPONSE_BODY_EVENT -> eventSpans[CONNECTION_EVENT] + else -> callRootSpan + } ?: callRootSpan } diff --git a/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEventListener.kt b/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEventListener.kt index accc715c70..c2418bd9ab 100644 --- a/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEventListener.kt +++ b/sentry-android-okhttp/src/main/java/io/sentry/android/okhttp/SentryOkHttpEventListener.kt @@ -313,7 +313,10 @@ class SentryOkHttpEventListener( okHttpEvent.setResponse(response) okHttpEvent.finishSpan(RESPONSE_HEADERS_EVENT) { it.setData(SpanDataConvention.HTTP_STATUS_CODE_KEY, response.code) - it.status = SpanStatus.fromHttpStatusCode(response.code) + // Let's not override the status of a span that was set + if (it.status == null) { + it.status = SpanStatus.fromHttpStatusCode(response.code) + } } } diff --git a/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventListenerTest.kt b/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventListenerTest.kt index 6348027f65..ede442eaa7 100644 --- a/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventListenerTest.kt +++ b/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventListenerTest.kt @@ -19,6 +19,7 @@ import okhttp3.mockwebserver.MockResponse import okhttp3.mockwebserver.MockWebServer import okhttp3.mockwebserver.SocketPolicy import org.mockito.kotlin.any +import org.mockito.kotlin.anyOrNull import org.mockito.kotlin.eq import org.mockito.kotlin.mock import org.mockito.kotlin.spy @@ -249,7 +250,7 @@ class SentryOkHttpEventListenerTest { @Test fun `propagate all calls to the event listener passed in the ctor`() { - val sut = fixture.getSut(eventListener = fixture.mockEventListener, httpStatusCode = 500) + val sut = fixture.getSut(eventListener = fixture.mockEventListener) val listener = fixture.sentryOkHttpEventListener val request = postRequest(body = "requestBody") val call = sut.newCall(request) @@ -260,7 +261,7 @@ class SentryOkHttpEventListenerTest { @Test fun `propagate all calls to the event listener factory passed in the ctor`() { - val sut = fixture.getSut(eventListenerFactory = fixture.mockEventListenerFactory, httpStatusCode = 500) + val sut = fixture.getSut(eventListenerFactory = fixture.mockEventListenerFactory) val listener = fixture.sentryOkHttpEventListener val request = postRequest(body = "requestBody") val call = sut.newCall(request) @@ -272,7 +273,7 @@ class SentryOkHttpEventListenerTest { @Test fun `propagate all calls to the SentryOkHttpEventListener passed in the ctor`() { val originalListener = spy(SentryOkHttpEventListener(fixture.hub, fixture.mockEventListener)) - val sut = fixture.getSut(eventListener = originalListener, httpStatusCode = 500) + val sut = fixture.getSut(eventListener = originalListener) val listener = fixture.sentryOkHttpEventListener val request = postRequest(body = "requestBody") val call = sut.newCall(request) @@ -284,7 +285,7 @@ class SentryOkHttpEventListenerTest { @Test fun `propagate all calls to the SentryOkHttpEventListener factory passed in the ctor`() { val originalListener = spy(SentryOkHttpEventListener(fixture.hub, fixture.mockEventListener)) - val sut = fixture.getSut(eventListenerFactory = { originalListener }, httpStatusCode = 500) + val sut = fixture.getSut(eventListenerFactory = { originalListener }) val listener = fixture.sentryOkHttpEventListener val request = postRequest(body = "requestBody") val call = sut.newCall(request) @@ -305,6 +306,49 @@ class SentryOkHttpEventListenerTest { assertEquals(9, fixture.sentryTracer.children.size) } + @Test + fun `status propagates to parent span and call root span`() { + val sut = fixture.getSut(httpStatusCode = 500) + val request = getRequest() + val call = sut.newCall(request) + val response = call.execute() + val okHttpEvent = SentryOkHttpEventListener.eventMap[call] + val callSpan = okHttpEvent?.callRootSpan + val responseHeaderSpan = + fixture.sentryTracer.children.firstOrNull { it.operation == "http.client.response_headers" } + val connectionSpan = fixture.sentryTracer.children.firstOrNull { it.operation == "http.client.connection" } + response.close() + assertNotNull(callSpan) + assertNotNull(responseHeaderSpan) + assertNotNull(connectionSpan) + assertEquals(SpanStatus.fromHttpStatusCode(500), callSpan.status) + assertEquals(SpanStatus.fromHttpStatusCode(500), responseHeaderSpan.status) + assertEquals(SpanStatus.fromHttpStatusCode(500), connectionSpan.status) + } + + @Test + fun `call root span status is not overridden if not null`() { + val mockListener = mock() + lateinit var call: Call + whenever(mockListener.connectStart(any(), anyOrNull(), anyOrNull())).then { + val okHttpEvent = SentryOkHttpEventListener.eventMap[call] + val callSpan = okHttpEvent?.callRootSpan + assertNotNull(callSpan) + assertNull(callSpan.status) + callSpan.status = SpanStatus.UNKNOWN + it + } + val sut = fixture.getSut(eventListener = mockListener) + val request = getRequest() + call = sut.newCall(request) + val response = call.execute() + val okHttpEvent = SentryOkHttpEventListener.eventMap[call] + val callSpan = okHttpEvent?.callRootSpan + assertNotNull(callSpan) + response.close() + assertEquals(SpanStatus.UNKNOWN, callSpan.status) + } + private fun verifyDelegation( listener: SentryOkHttpEventListener, originalListener: EventListener, diff --git a/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventTest.kt b/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventTest.kt index 54fe8cef65..d4d84d829d 100644 --- a/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventTest.kt +++ b/sentry-android-okhttp/src/test/java/io/sentry/android/okhttp/SentryOkHttpEventTest.kt @@ -8,6 +8,7 @@ import io.sentry.SentryTracer import io.sentry.Span import io.sentry.SpanDataConvention import io.sentry.SpanOptions +import io.sentry.SpanStatus import io.sentry.TracesSamplingDecision import io.sentry.TransactionContext import io.sentry.TypeCheckHint @@ -242,6 +243,28 @@ class SentryOkHttpEventTest { ) } + @Test + fun `when finishEvent, all running spans are finished with internal_error status`() { + val sut = fixture.getSut() + sut.startSpan("span") + val spans = sut.getEventSpans() + assertNull(spans["span"]!!.status) + sut.finishEvent() + assertEquals(SpanStatus.INTERNAL_ERROR, spans["span"]!!.status) + } + + @Test + fun `when finishEvent, does not override running spans status if set`() { + val sut = fixture.getSut() + sut.startSpan("span") + val spans = sut.getEventSpans() + assertNull(spans["span"]!!.status) + spans["span"]!!.status = SpanStatus.OK + assertEquals(SpanStatus.OK, spans["span"]!!.status) + sut.finishEvent() + assertEquals(SpanStatus.OK, spans["span"]!!.status) + } + @Test fun `setResponse set protocol and code in the breadcrumb and root span, and response in the hint`() { val sut = fixture.getSut() @@ -443,6 +466,32 @@ class SentryOkHttpEventTest { assertEquals(rootSpan.spanId, responseBodySpan?.parentSpanId) } + @Test + fun `finishSpan beforeFinish is called on span, parent and call root span`() { + val sut = fixture.getSut() + sut.startSpan(CONNECTION_EVENT) + sut.startSpan(REQUEST_HEADERS_EVENT) + sut.startSpan("random event") + sut.finishSpan(REQUEST_HEADERS_EVENT) { it.status = SpanStatus.INTERNAL_ERROR } + sut.finishSpan("random event") { it.status = SpanStatus.DEADLINE_EXCEEDED } + sut.finishSpan(CONNECTION_EVENT) + val spans = sut.getEventSpans() + val connectionSpan = spans[CONNECTION_EVENT] as Span? + val requestHeadersSpan = spans[REQUEST_HEADERS_EVENT] as Span? + val randomEventSpan = spans["random event"] as Span? + assertNotNull(connectionSpan) + assertNotNull(requestHeadersSpan) + assertNotNull(randomEventSpan) + // requestHeadersSpan was finished with INTERNAL_ERROR + assertEquals(SpanStatus.INTERNAL_ERROR, requestHeadersSpan.status) + // randomEventSpan was finished with DEADLINE_EXCEEDED + assertEquals(SpanStatus.DEADLINE_EXCEEDED, randomEventSpan.status) + // requestHeadersSpan was finished with INTERNAL_ERROR, and it propagates to its parent + assertEquals(SpanStatus.INTERNAL_ERROR, connectionSpan.status) + // random event was finished last with DEADLINE_EXCEEDED, and it propagates to root call + assertEquals(SpanStatus.DEADLINE_EXCEEDED, sut.callRootSpan!!.status) + } + /** Retrieve all the spans started in the event using reflection. */ private fun SentryOkHttpEvent.getEventSpans() = getProperty>("eventSpans") }