diff --git a/CHANGELOG.md b/CHANGELOG.md index f0dc7b60a9..5c98d33c41 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,11 @@ ## Unreleased +### Breaking Changes + +- Change OkHttp sub-spans to span attributes ([#3556](https://github.com/getsentry/sentry-java/pull/3556)) + - This will reduce the number of spans created by the SDK + ### Fixes - Use OpenTelemetry span name as fallback for transaction name ([#3557](https://github.com/getsentry/sentry-java/pull/3557)) diff --git a/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEvent.kt b/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEvent.kt index 28d7375450..7aacadd4d1 100644 --- a/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEvent.kt +++ b/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEvent.kt @@ -5,38 +5,28 @@ import io.sentry.Hint import io.sentry.IScopes import io.sentry.ISpan import io.sentry.SentryDate -import io.sentry.SentryLevel import io.sentry.SpanDataConvention import io.sentry.TypeCheckHint -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.CONNECTION_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.CONNECT_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.REQUEST_BODY_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.REQUEST_HEADERS_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.RESPONSE_BODY_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.RESPONSE_HEADERS_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.SECURE_CONNECT_EVENT import io.sentry.util.Platform import io.sentry.util.UrlUtils import okhttp3.Request import okhttp3.Response import java.util.Locale import java.util.concurrent.ConcurrentHashMap -import java.util.concurrent.RejectedExecutionException +import java.util.concurrent.TimeUnit import java.util.concurrent.atomic.AtomicBoolean private const val PROTOCOL_KEY = "protocol" private const val ERROR_MESSAGE_KEY = "error_message" -private const val RESPONSE_BODY_TIMEOUT_MILLIS = 800L internal const val TRACE_ORIGIN = "auto.http.okhttp" @Suppress("TooManyFunctions") internal class SentryOkHttpEvent(private val scopes: IScopes, private val request: Request) { - private val eventSpans: MutableMap = ConcurrentHashMap() + private val eventDates: MutableMap = ConcurrentHashMap() private val breadcrumb: Breadcrumb - internal val callRootSpan: ISpan? + internal val callSpan: ISpan? private var response: Response? = null private var clientErrorResponse: Response? = null - private val isReadingResponseBody = AtomicBoolean(false) private val isEventFinished = AtomicBoolean(false) private val url: String private val method: String @@ -50,52 +40,52 @@ internal class SentryOkHttpEvent(private val scopes: IScopes, private val reques // We start the call span that will contain all the others val parentSpan = if (Platform.isAndroid()) scopes.transaction else scopes.span - callRootSpan = parentSpan?.startChild("http.client", "$method $url") - callRootSpan?.spanContext?.origin = TRACE_ORIGIN - urlDetails.applyToSpan(callRootSpan) + callSpan = parentSpan?.startChild("http.client", "$method $url") + callSpan?.spanContext?.origin = TRACE_ORIGIN + urlDetails.applyToSpan(callSpan) // We setup a breadcrumb with all meaningful data breadcrumb = Breadcrumb.http(url, method) breadcrumb.setData("host", host) breadcrumb.setData("path", encodedPath) - // We add the same data to the root call span - callRootSpan?.setData("url", url) - callRootSpan?.setData("host", host) - callRootSpan?.setData("path", encodedPath) - callRootSpan?.setData(SpanDataConvention.HTTP_METHOD_KEY, method.uppercase(Locale.ROOT)) + // We add the same data to the call span + callSpan?.setData("url", url) + callSpan?.setData("host", host) + callSpan?.setData("path", encodedPath) + callSpan?.setData(SpanDataConvention.HTTP_METHOD_KEY, method.uppercase(Locale.ROOT)) } /** * Sets the [Response] that will be sent in the breadcrumb [Hint]. - * Also, it sets the protocol and status code in the breadcrumb and the call root span. + * Also, it sets the protocol and status code in the breadcrumb and the call span. */ fun setResponse(response: Response) { this.response = response breadcrumb.setData(PROTOCOL_KEY, response.protocol.name) breadcrumb.setData("status_code", response.code) - callRootSpan?.setData(PROTOCOL_KEY, response.protocol.name) - callRootSpan?.setData(SpanDataConvention.HTTP_STATUS_CODE_KEY, response.code) + callSpan?.setData(PROTOCOL_KEY, response.protocol.name) + callSpan?.setData(SpanDataConvention.HTTP_STATUS_CODE_KEY, response.code) } fun setProtocol(protocolName: String?) { if (protocolName != null) { breadcrumb.setData(PROTOCOL_KEY, protocolName) - callRootSpan?.setData(PROTOCOL_KEY, protocolName) + callSpan?.setData(PROTOCOL_KEY, protocolName) } } fun setRequestBodySize(byteCount: Long) { if (byteCount > -1) { breadcrumb.setData("request_content_length", byteCount) - callRootSpan?.setData("http.request_content_length", byteCount) + callSpan?.setData("http.request_content_length", byteCount) } } fun setResponseBodySize(byteCount: Long) { if (byteCount > -1) { breadcrumb.setData("response_content_length", byteCount) - callRootSpan?.setData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY, byteCount) + callSpan?.setData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY, byteCount) } } @@ -107,44 +97,33 @@ internal class SentryOkHttpEvent(private val scopes: IScopes, private val reques fun setError(errorMessage: String?) { if (errorMessage != null) { breadcrumb.setData(ERROR_MESSAGE_KEY, errorMessage) - callRootSpan?.setData(ERROR_MESSAGE_KEY, errorMessage) + callSpan?.setData(ERROR_MESSAGE_KEY, errorMessage) } } - /** 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 = findParentSpan(event) - val span = parentSpan?.startChild("http.client.$event", "$method $url") ?: return - if (event == RESPONSE_BODY_EVENT) { - // We save this event is reading the response body, so that it will not be auto-finished - isReadingResponseBody.set(true) - } - span.spanContext.origin = TRACE_ORIGIN - eventSpans[event] = span + /** Record event start if the callRootSpan is not null. */ + fun onEventStart(event: String) { + callSpan ?: return + eventDates[event] = scopes.options.dateProvider.now() } - /** 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): ISpan? { - val span = eventSpans[event] ?: return null - val parentSpan = findParentSpan(event) - beforeFinish?.invoke(span) - moveThrowableToRootSpan(span) - if (parentSpan != null && parentSpan != callRootSpan) { - beforeFinish?.invoke(parentSpan) - moveThrowableToRootSpan(parentSpan) - } - callRootSpan?.let { beforeFinish?.invoke(it) } - span.finish() - return span + /** Record event finish and runs [beforeFinish] on the call span. */ + fun onEventFinish(event: String, beforeFinish: ((span: ISpan) -> Unit)? = null) { + val eventDate = eventDates.remove(event) ?: return + callSpan ?: return + beforeFinish?.invoke(callSpan) + val eventDurationNanos = scopes.options.dateProvider.now().diff(eventDate) + callSpan.setData(event, TimeUnit.NANOSECONDS.toMillis(eventDurationNanos)) } - /** Finishes the call root span, and runs [beforeFinish] on it. Then a breadcrumb is sent. */ - fun finishEvent(finishDate: SentryDate? = null, beforeFinish: ((span: ISpan) -> Unit)? = null) { + /** Finishes the call span, and runs [beforeFinish] on it. Then a breadcrumb is sent. */ + fun finish(beforeFinish: ((span: ISpan) -> Unit)? = null) { // If the event already finished, we don't do anything if (isEventFinished.getAndSet(true)) { return } + // We clear any date left, in case an event started, but never finished. Shouldn't happen. + eventDates.clear() // We put data in the hint and send a breadcrumb val hint = Hint() hint.set(TypeCheckHint.OKHTTP_REQUEST, request) @@ -153,75 +132,12 @@ internal class SentryOkHttpEvent(private val scopes: IScopes, private val reques // We send the breadcrumb even without spans. scopes.addBreadcrumb(breadcrumb, hint) - // No span is created (e.g. no transaction is running) - if (callRootSpan == null) { - // We report the client error even without spans. - clientErrorResponse?.let { - SentryOkHttpUtils.captureClientError(scopes, it.request, it) - } - return - } - - // We forcefully finish all spans, even if they should already have been finished through finishSpan() - eventSpans.values.filter { !it.isFinished }.forEach { - moveThrowableToRootSpan(it) - if (finishDate != null) { - it.finish(it.status, finishDate) - } else { - it.finish() - } - } - beforeFinish?.invoke(callRootSpan) - // We report the client error here, after all sub-spans finished, so that it will be bound - // to the root call span. + callSpan?.let { beforeFinish?.invoke(it) } + // We report the client error here so that it will be bound to the call span. We send it even if there is no running span. clientErrorResponse?.let { SentryOkHttpUtils.captureClientError(scopes, it.request, it) } - if (finishDate != null) { - callRootSpan.finish(callRootSpan.status, finishDate) - } else { - callRootSpan.finish() - } + callSpan?.finish() return } - - /** Move any throwable from an inner span to the call root span. */ - private fun moveThrowableToRootSpan(span: ISpan) { - if (span != callRootSpan && span.throwable != null && span.status != null) { - callRootSpan?.throwable = span.throwable - callRootSpan?.status = span.status - span.throwable = null - } - } - - 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 - - fun scheduleFinish(timestamp: SentryDate) { - try { - scopes.options.executorService.schedule({ - if (!isReadingResponseBody.get() && - (eventSpans.values.all { it.isFinished } || callRootSpan?.isFinished != true) - ) { - finishEvent(timestamp) - } - }, RESPONSE_BODY_TIMEOUT_MILLIS) - } catch (e: RejectedExecutionException) { - scopes.options - .logger - .log( - SentryLevel.ERROR, - "Failed to call the executor. OkHttp span will not be finished " + - "automatically. Did you call Sentry.close()?", - e - ) - } - } } diff --git a/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEventListener.kt b/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEventListener.kt index b9595af115..9e6ed3019f 100644 --- a/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEventListener.kt +++ b/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpEventListener.kt @@ -48,15 +48,15 @@ public open class SentryOkHttpEventListener( private var originalEventListener: EventListener? = null public companion object { - internal const val PROXY_SELECT_EVENT = "proxy_select" - internal const val DNS_EVENT = "dns" - internal const val SECURE_CONNECT_EVENT = "secure_connect" - internal const val CONNECT_EVENT = "connect" - internal const val CONNECTION_EVENT = "connection" - internal const val REQUEST_HEADERS_EVENT = "request_headers" - internal const val REQUEST_BODY_EVENT = "request_body" - internal const val RESPONSE_HEADERS_EVENT = "response_headers" - internal const val RESPONSE_BODY_EVENT = "response_body" + internal const val PROXY_SELECT_EVENT = "http.client.proxy_select_ms" + internal const val DNS_EVENT = "http.client.resolve_dns_ms" + internal const val CONNECT_EVENT = "http.connect_ms" + internal const val SECURE_CONNECT_EVENT = "http.connect.secure_connect_ms" + internal const val CONNECTION_EVENT = "http.connection_ms" + internal const val REQUEST_HEADERS_EVENT = "http.connection.request_headers_ms" + internal const val REQUEST_BODY_EVENT = "http.connection.request_body_ms" + internal const val RESPONSE_HEADERS_EVENT = "http.connection.response_headers_ms" + internal const val RESPONSE_BODY_EVENT = "http.connection.response_body_ms" internal val eventMap: MutableMap = ConcurrentHashMap() } @@ -102,7 +102,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(PROXY_SELECT_EVENT) + okHttpEvent.onEventStart(PROXY_SELECT_EVENT) } override fun proxySelectEnd( @@ -115,7 +115,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.finishSpan(PROXY_SELECT_EVENT) { + okHttpEvent.onEventFinish(PROXY_SELECT_EVENT) { if (proxies.isNotEmpty()) { it.setData("proxies", proxies.joinToString { proxy -> proxy.toString() }) } @@ -128,7 +128,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(DNS_EVENT) + okHttpEvent.onEventStart(DNS_EVENT) } override fun dnsEnd( @@ -141,7 +141,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.finishSpan(DNS_EVENT) { + okHttpEvent.onEventFinish(DNS_EVENT) { it.setData("domain_name", domainName) if (inetAddressList.isNotEmpty()) { it.setData("dns_addresses", inetAddressList.joinToString { address -> address.toString() }) @@ -159,7 +159,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(CONNECT_EVENT) + okHttpEvent.onEventStart(CONNECT_EVENT) } override fun secureConnectStart(call: Call) { @@ -168,7 +168,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(SECURE_CONNECT_EVENT) + okHttpEvent.onEventStart(SECURE_CONNECT_EVENT) } override fun secureConnectEnd(call: Call, handshake: Handshake?) { @@ -177,7 +177,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.finishSpan(SECURE_CONNECT_EVENT) + okHttpEvent.onEventFinish(SECURE_CONNECT_EVENT) } override fun connectEnd( @@ -192,7 +192,7 @@ public open class SentryOkHttpEventListener( } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return okHttpEvent.setProtocol(protocol?.name) - okHttpEvent.finishSpan(CONNECT_EVENT) + okHttpEvent.onEventFinish(CONNECT_EVENT) } override fun connectFailed( @@ -209,7 +209,7 @@ public open class SentryOkHttpEventListener( val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return okHttpEvent.setProtocol(protocol?.name) okHttpEvent.setError(ioe.message) - okHttpEvent.finishSpan(CONNECT_EVENT) { + okHttpEvent.onEventFinish(CONNECT_EVENT) { it.throwable = ioe it.status = SpanStatus.INTERNAL_ERROR } @@ -221,7 +221,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(CONNECTION_EVENT) + okHttpEvent.onEventStart(CONNECTION_EVENT) } override fun connectionReleased(call: Call, connection: Connection) { @@ -230,7 +230,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.finishSpan(CONNECTION_EVENT) + okHttpEvent.onEventFinish(CONNECTION_EVENT) } override fun requestHeadersStart(call: Call) { @@ -239,7 +239,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(REQUEST_HEADERS_EVENT) + okHttpEvent.onEventStart(REQUEST_HEADERS_EVENT) } override fun requestHeadersEnd(call: Call, request: Request) { @@ -248,7 +248,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.finishSpan(REQUEST_HEADERS_EVENT) + okHttpEvent.onEventFinish(REQUEST_HEADERS_EVENT) } override fun requestBodyStart(call: Call) { @@ -257,7 +257,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(REQUEST_BODY_EVENT) + okHttpEvent.onEventStart(REQUEST_BODY_EVENT) } override fun requestBodyEnd(call: Call, byteCount: Long) { @@ -266,7 +266,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.finishSpan(REQUEST_BODY_EVENT) { + okHttpEvent.onEventFinish(REQUEST_BODY_EVENT) { if (byteCount > 0) { it.setData("http.request_content_length", byteCount) } @@ -283,13 +283,13 @@ public open class SentryOkHttpEventListener( okHttpEvent.setError(ioe.message) // requestFailed can happen after requestHeaders or requestBody. // If requestHeaders already finished, we don't change its status. - okHttpEvent.finishSpan(REQUEST_HEADERS_EVENT) { + okHttpEvent.onEventFinish(REQUEST_HEADERS_EVENT) { if (!it.isFinished) { it.status = SpanStatus.INTERNAL_ERROR it.throwable = ioe } } - okHttpEvent.finishSpan(REQUEST_BODY_EVENT) { + okHttpEvent.onEventFinish(REQUEST_BODY_EVENT) { it.status = SpanStatus.INTERNAL_ERROR it.throwable = ioe } @@ -301,7 +301,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(RESPONSE_HEADERS_EVENT) + okHttpEvent.onEventStart(RESPONSE_HEADERS_EVENT) } override fun responseHeadersEnd(call: Call, response: Response) { @@ -311,14 +311,13 @@ public open class SentryOkHttpEventListener( } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return okHttpEvent.setResponse(response) - val responseHeadersSpan = okHttpEvent.finishSpan(RESPONSE_HEADERS_EVENT) { + okHttpEvent.onEventFinish(RESPONSE_HEADERS_EVENT) { it.setData(SpanDataConvention.HTTP_STATUS_CODE_KEY, response.code) // Let's not override the status of a span that was set if (it.status == null) { it.status = SpanStatus.fromHttpStatusCode(response.code) } } - okHttpEvent.scheduleFinish(responseHeadersSpan?.finishDate ?: scopes.options.dateProvider.now()) } override fun responseBodyStart(call: Call) { @@ -327,7 +326,7 @@ public open class SentryOkHttpEventListener( return } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return - okHttpEvent.startSpan(RESPONSE_BODY_EVENT) + okHttpEvent.onEventStart(RESPONSE_BODY_EVENT) } override fun responseBodyEnd(call: Call, byteCount: Long) { @@ -337,7 +336,7 @@ public open class SentryOkHttpEventListener( } val okHttpEvent: SentryOkHttpEvent = eventMap[call] ?: return okHttpEvent.setResponseBodySize(byteCount) - okHttpEvent.finishSpan(RESPONSE_BODY_EVENT) { + okHttpEvent.onEventFinish(RESPONSE_BODY_EVENT) { if (byteCount > 0) { it.setData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY, byteCount) } @@ -353,13 +352,13 @@ public open class SentryOkHttpEventListener( okHttpEvent.setError(ioe.message) // responseFailed can happen after responseHeaders or responseBody. // If responseHeaders already finished, we don't change its status. - okHttpEvent.finishSpan(RESPONSE_HEADERS_EVENT) { + okHttpEvent.onEventFinish(RESPONSE_HEADERS_EVENT) { if (!it.isFinished) { it.status = SpanStatus.INTERNAL_ERROR it.throwable = ioe } } - okHttpEvent.finishSpan(RESPONSE_BODY_EVENT) { + okHttpEvent.onEventFinish(RESPONSE_BODY_EVENT) { it.status = SpanStatus.INTERNAL_ERROR it.throwable = ioe } @@ -368,7 +367,7 @@ public open class SentryOkHttpEventListener( override fun callEnd(call: Call) { originalEventListener?.callEnd(call) val okHttpEvent: SentryOkHttpEvent = eventMap.remove(call) ?: return - okHttpEvent.finishEvent() + okHttpEvent.finish() } override fun callFailed(call: Call, ioe: IOException) { @@ -378,7 +377,7 @@ public open class SentryOkHttpEventListener( } val okHttpEvent: SentryOkHttpEvent = eventMap.remove(call) ?: return okHttpEvent.setError(ioe.message) - okHttpEvent.finishEvent { + okHttpEvent.finish { it.status = SpanStatus.INTERNAL_ERROR it.throwable = ioe } diff --git a/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpInterceptor.kt b/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpInterceptor.kt index a079864612..2bd7b03d43 100644 --- a/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpInterceptor.kt +++ b/sentry-okhttp/src/main/java/io/sentry/okhttp/SentryOkHttpInterceptor.kt @@ -72,7 +72,7 @@ public open class SentryOkHttpInterceptor( if (SentryOkHttpEventListener.eventMap.containsKey(chain.call())) { // read the span from the event listener okHttpEvent = SentryOkHttpEventListener.eventMap[chain.call()] - span = okHttpEvent?.callRootSpan + span = okHttpEvent?.callSpan } else { // read the span from the bound scope okHttpEvent = null @@ -133,7 +133,7 @@ public open class SentryOkHttpInterceptor( } throw e } finally { - finishSpan(span, request, response, isFromEventListener) + finishSpan(span, request, response, isFromEventListener, okHttpEvent) // The SentryOkHttpEventListener will send the breadcrumb itself if used for this call if (!isFromEventListener) { @@ -160,7 +160,7 @@ public open class SentryOkHttpInterceptor( scopes.addBreadcrumb(breadcrumb, hint) } - private fun finishSpan(span: ISpan?, request: Request, response: Response?, isFromEventListener: Boolean) { + private fun finishSpan(span: ISpan?, request: Request, response: Response?, isFromEventListener: Boolean, okHttpEvent: SentryOkHttpEvent?) { if (span == null) { return } @@ -170,16 +170,12 @@ public open class SentryOkHttpInterceptor( // span is dropped span.spanContext.sampled = false } - // The SentryOkHttpEventListener will finish the span itself if used for this call - if (!isFromEventListener) { - span.finish() - } - } else { - // The SentryOkHttpEventListener will finish the span itself if used for this call - if (!isFromEventListener) { - span.finish() - } } + if (!isFromEventListener) { + span.finish() + } + // The SentryOkHttpEventListener waits until the response is closed (which may never happen), so we close it here + okHttpEvent?.finish() } private fun Long?.ifHasValidLength(fn: (Long) -> Unit) { diff --git a/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventListenerTest.kt b/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventListenerTest.kt index 388b494547..ab179189b4 100644 --- a/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventListenerTest.kt +++ b/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventListenerTest.kt @@ -8,7 +8,6 @@ import io.sentry.SentryTracer import io.sentry.SpanDataConvention import io.sentry.SpanStatus import io.sentry.TransactionContext -import io.sentry.test.ImmediateExecutorService import okhttp3.Call import okhttp3.EventListener import okhttp3.OkHttpClient @@ -23,7 +22,6 @@ import org.mockito.kotlin.any import org.mockito.kotlin.anyOrNull import org.mockito.kotlin.eq import org.mockito.kotlin.mock -import org.mockito.kotlin.never import org.mockito.kotlin.spy import org.mockito.kotlin.verify import org.mockito.kotlin.whenever @@ -135,7 +133,7 @@ class SentryOkHttpEventListenerTest { val call = sut.newCall(request) val response = call.execute() val okHttpEvent = SentryOkHttpEventListener.eventMap[call] - val callSpan = okHttpEvent?.callRootSpan + val callSpan = okHttpEvent?.callSpan response.close() assertNotNull(callSpan) assertEquals(callSpan, fixture.sentryTracer.children.first()) @@ -146,76 +144,40 @@ class SentryOkHttpEventListenerTest { } @Test - fun `creates a span for each event`() { + fun `adds a data for each event`() { val sut = fixture.getSut() val request = getRequest() val call = sut.newCall(request) val response = call.execute() val okHttpEvent = SentryOkHttpEventListener.eventMap[call] - val callSpan = okHttpEvent?.callRootSpan + val callSpan = okHttpEvent?.callSpan response.close() - assertEquals(8, fixture.sentryTracer.children.size) - fixture.sentryTracer.children.forEachIndexed { index, span -> - assertTrue(span.isFinished) - when (index) { - 0 -> { - assertEquals(callSpan, span) - assertEquals("GET ${request.url}", span.description) - assertNotNull(span.data["proxies"]) - assertNotNull(span.data["domain_name"]) - assertNotNull(span.data["dns_addresses"]) - assertEquals(201, span.data[SpanDataConvention.HTTP_STATUS_CODE_KEY]) - } - 1 -> { - assertEquals("http.client.proxy_select", span.operation) - assertEquals("GET ${request.url}", span.description) - assertNotNull(span.data["proxies"]) - } - 2 -> { - assertEquals("http.client.dns", span.operation) - assertEquals("GET ${request.url}", span.description) - assertNotNull(span.data["domain_name"]) - assertNotNull(span.data["dns_addresses"]) - } - 3 -> { - assertEquals("http.client.connect", span.operation) - assertEquals("GET ${request.url}", span.description) - } - 4 -> { - assertEquals("http.client.connection", span.operation) - assertEquals("GET ${request.url}", span.description) - } - 5 -> { - assertEquals("http.client.request_headers", span.operation) - assertEquals("GET ${request.url}", span.description) - } - 6 -> { - assertEquals("http.client.response_headers", span.operation) - assertEquals("GET ${request.url}", span.description) - assertEquals(201, span.data[SpanDataConvention.HTTP_STATUS_CODE_KEY]) - } - 7 -> { - assertEquals("http.client.response_body", span.operation) - assertEquals("GET ${request.url}", span.description) - } - } - } + assertEquals(1, fixture.sentryTracer.children.size) + assertNotNull(callSpan) + assertNotNull(callSpan.getData("proxies")) + assertNotNull(callSpan.getData("domain_name")) + assertNotNull(callSpan.getData("dns_addresses")) + assertEquals(201, callSpan.getData(SpanDataConvention.HTTP_STATUS_CODE_KEY)) + assertNotNull(callSpan.getData("http.client.proxy_select_ms")) + assertNotNull(callSpan.getData("http.client.resolve_dns_ms")) + assertNotNull(callSpan.getData("http.connect_ms")) + assertNotNull(callSpan.getData("http.connection_ms")) + assertNotNull(callSpan.getData("http.connection.request_headers_ms")) + assertNotNull(callSpan.getData("http.connection.response_headers_ms")) + assertNotNull(callSpan.getData("http.connection.response_body_ms")) } @Test - fun `has requestBody span for requests with body`() { + fun `has requestBody data for requests with body`() { val sut = fixture.getSut() val requestBody = "request body sent in the request" val request = postRequest(body = requestBody) val call = sut.newCall(request) val response = call.execute() val okHttpEvent = SentryOkHttpEventListener.eventMap[call] - val callSpan = okHttpEvent?.callRootSpan + val callSpan = okHttpEvent?.callSpan response.close() - assertEquals(9, fixture.sentryTracer.children.size) - val requestBodySpan = fixture.sentryTracer.children.firstOrNull { it.operation == "http.client.request_body" } - assertNotNull(requestBodySpan) - assertEquals(requestBody.toByteArray().size.toLong(), requestBodySpan.data["http.request_content_length"]) + assertNotNull(callSpan?.getData("http.connection.request_body_ms")) assertEquals(requestBody.toByteArray().size.toLong(), callSpan?.getData("http.request_content_length")) } @@ -227,19 +189,15 @@ class SentryOkHttpEventListenerTest { val call = sut.newCall(request) val response = call.execute() val okHttpEvent = SentryOkHttpEventListener.eventMap[call] - val callSpan = okHttpEvent?.callRootSpan + val callSpan = okHttpEvent?.callSpan + assertNull(callSpan?.getData("http.connection.response_body_ms")) // Consume the response val responseBytes = response.body?.byteStream()?.readBytes() assertNotNull(responseBytes) + assertNotNull(callSpan?.getData("http.connection.response_body_ms")) response.close() - val requestBodySpan = fixture.sentryTracer.children.firstOrNull { it.operation == "http.client.response_body" } - assertNotNull(requestBodySpan) - assertEquals( - responseBytes.size.toLong(), - requestBodySpan.data[SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY] - ) assertEquals( responseBytes.size.toLong(), callSpan?.getData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY) @@ -247,13 +205,13 @@ class SentryOkHttpEventListenerTest { } @Test - fun `root call span status depends on http status code`() { + fun `call span status depends on http status code`() { val sut = fixture.getSut(httpStatusCode = 404) val request = getRequest() val call = sut.newCall(request) val response = call.execute() val okHttpEvent = SentryOkHttpEventListener.eventMap[call] - val callSpan = okHttpEvent?.callRootSpan + val callSpan = okHttpEvent?.callSpan response.close() assertNotNull(callSpan) assertEquals(SpanStatus.fromHttpStatusCode(404), callSpan.status) @@ -314,79 +272,16 @@ class SentryOkHttpEventListenerTest { val response = call.execute() response.close() // Spans are created by the originalListener, so the listener doesn't create duplicates - 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 `when response is not closed, root call is trimmed to responseHeadersEnd`() { - val sut = fixture.getSut( - httpStatusCode = 500, - configureOptions = { it.executorService = ImmediateExecutorService() } - ) - val request = getRequest() - val call = sut.newCall(request) - val response = spy(call.execute()) - val okHttpEvent = SentryOkHttpEventListener.eventMap[call] - val callSpan = okHttpEvent?.callRootSpan - val responseHeaderSpan = - fixture.sentryTracer.children.firstOrNull { it.operation == "http.client.response_headers" } - val responseBodySpan = fixture.sentryTracer.children.firstOrNull { it.operation == "http.client.response_body" } - - // Response is not finished - verify(response, never()).close() - - // response body span is never started - assertNull(responseBodySpan) - - assertNotNull(callSpan) - assertNotNull(responseHeaderSpan) - - // Call span is trimmed to responseHeader finishTimestamp - assertEquals(callSpan.finishDate?.nanoTimestamp(), responseHeaderSpan.finishDate?.nanoTimestamp()) - - // All children spans of the root call are finished - assertTrue(fixture.sentryTracer.children.all { it.isFinished }) - } - - @Test - fun `responseHeadersEnd schedules event finish`() { - val listener = SentryOkHttpEventListener(fixture.scopes, fixture.mockEventListener) - whenever(fixture.scopes.options).thenReturn(SentryOptions()) - val call = mock() - whenever(call.request()).thenReturn(getRequest()) - val okHttpEvent = mock() - SentryOkHttpEventListener.eventMap[call] = okHttpEvent - listener.responseHeadersEnd(call, mock()) - verify(okHttpEvent).scheduleFinish(any()) + assertEquals(1, fixture.sentryTracer.children.size) } @Test - fun `call root span status is not overridden if not null`() { + fun `call 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 + val callSpan = okHttpEvent?.callSpan assertNotNull(callSpan) assertNull(callSpan.status) callSpan.status = SpanStatus.UNKNOWN @@ -397,7 +292,7 @@ class SentryOkHttpEventListenerTest { call = sut.newCall(request) val response = call.execute() val okHttpEvent = SentryOkHttpEventListener.eventMap[call] - val callSpan = okHttpEvent?.callRootSpan + val callSpan = okHttpEvent?.callSpan assertNotNull(callSpan) response.close() assertEquals(SpanStatus.UNKNOWN, callSpan.status) diff --git a/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventTest.kt b/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventTest.kt index 37482b824f..33f9b04d85 100644 --- a/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventTest.kt +++ b/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpEventTest.kt @@ -3,7 +3,6 @@ package io.sentry.okhttp import io.sentry.Breadcrumb import io.sentry.Hint import io.sentry.IScopes -import io.sentry.ISentryExecutorService import io.sentry.ISpan import io.sentry.SentryDate import io.sentry.SentryOptions @@ -11,19 +10,10 @@ 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 import io.sentry.exception.SentryHttpClientException -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.CONNECTION_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.CONNECT_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.REQUEST_BODY_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.REQUEST_HEADERS_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.RESPONSE_BODY_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.RESPONSE_HEADERS_EVENT -import io.sentry.okhttp.SentryOkHttpEventListener.Companion.SECURE_CONNECT_EVENT -import io.sentry.test.ImmediateExecutorService import io.sentry.test.getProperty import okhttp3.Protocol import okhttp3.Request @@ -33,14 +23,11 @@ import org.mockito.kotlin.any import org.mockito.kotlin.anyOrNull import org.mockito.kotlin.argThat import org.mockito.kotlin.check -import org.mockito.kotlin.eq import org.mockito.kotlin.mock import org.mockito.kotlin.never -import org.mockito.kotlin.spy import org.mockito.kotlin.times import org.mockito.kotlin.verify import org.mockito.kotlin.whenever -import java.util.concurrent.RejectedExecutionException import kotlin.test.Test import kotlin.test.assertEquals import kotlin.test.assertFalse @@ -102,15 +89,15 @@ class SentryOkHttpEventTest { private val fixture = Fixture() @Test - fun `when there is no active span, root span is null`() { + fun `when there is no active span, call span is null`() { val sut = fixture.getSut(currentSpan = null) - assertNull(sut.callRootSpan) + assertNull(sut.callSpan) } @Test - fun `when there is an active span, a root span is created`() { + fun `when there is an active span, a call span is created`() { val sut = fixture.getSut() - val callSpan = sut.callRootSpan + val callSpan = sut.callSpan assertNotNull(callSpan) assertEquals("http.client", callSpan.operation) assertEquals("${fixture.mockRequest.method} ${fixture.mockRequest.url}", callSpan.description) @@ -121,126 +108,119 @@ class SentryOkHttpEventTest { } @Test - fun `when root span is null, breadcrumb is created anyway`() { + fun `when call span is null, breadcrumb is created anyway`() { val sut = fixture.getSut(currentSpan = null) - assertNull(sut.callRootSpan) - sut.finishEvent() + assertNull(sut.callSpan) + sut.finish() verify(fixture.scopes).addBreadcrumb(any(), anyOrNull()) } @Test - fun `when root span is null, no span is created`() { + fun `when call span is null, no event is recorded`() { val sut = fixture.getSut(currentSpan = null) - assertNull(sut.callRootSpan) - sut.startSpan("span") - assertTrue(sut.getEventSpans().isEmpty()) + assertNull(sut.callSpan) + sut.onEventStart("span") + assertTrue(sut.getEventDates().isEmpty()) } @Test - fun `when event is finished, root span is finished`() { + fun `when event is finished, call span is finished`() { val sut = fixture.getSut() - val rootSpan = sut.callRootSpan + val rootSpan = sut.callSpan assertNotNull(rootSpan) assertFalse(rootSpan.isFinished) - sut.finishEvent() + sut.finish() assertTrue(rootSpan.isFinished) } @Test - fun `when startSpan, a new span is started`() { + fun `when onEventStart, a new event is recorded`() { val sut = fixture.getSut() - assertTrue(sut.getEventSpans().isEmpty()) - sut.startSpan("span") - val spans = sut.getEventSpans() - assertEquals(1, spans.size) - val span = spans["span"] - assertNotNull(span) - assertTrue(spans.containsKey("span")) - assertEquals("http.client.span", span.operation) - assertEquals("${fixture.mockRequest.method} ${fixture.mockRequest.url}", span.description) - assertFalse(span.isFinished) + val callSpan = sut.callSpan + assertTrue(sut.getEventDates().isEmpty()) + sut.onEventStart("span") + val dates = sut.getEventDates() + assertEquals(1, dates.size) + assertNull(callSpan!!.getData("span")) } @Test - fun `when finishSpan, a span is finished if previously started`() { + fun `when onEventFinish, an event is added to call span`() { val sut = fixture.getSut() - assertTrue(sut.getEventSpans().isEmpty()) - sut.startSpan("span") - val spans = sut.getEventSpans() - assertFalse(spans["span"]!!.isFinished) - sut.finishSpan("span") - assertTrue(spans["span"]!!.isFinished) + val callSpan = sut.callSpan + assertTrue(sut.getEventDates().isEmpty()) + sut.onEventStart("span") + val dates = sut.getEventDates() + assertEquals(1, dates.size) + assertNull(callSpan!!.getData("span")) + sut.onEventFinish("span") + assertEquals(0, dates.size) + assertNotNull(callSpan.getData("span")) } @Test - fun `when finishSpan, a callback is called before the span is finished`() { + fun `when onEventFinish, a callback is called before the event is set`() { val sut = fixture.getSut() + val callSpan = sut.callSpan var called = false - assertTrue(sut.getEventSpans().isEmpty()) - sut.startSpan("span") - val spans = sut.getEventSpans() - assertFalse(spans["span"]!!.isFinished) - sut.finishSpan("span") { + assertTrue(sut.getEventDates().isEmpty()) + sut.onEventStart("span") + assertNull(callSpan!!.getData("span")) + sut.onEventFinish("span") { called = true - assertFalse(it.isFinished) + assertNull(callSpan.getData("span")) } - assertTrue(spans["span"]!!.isFinished) + assertNotNull(callSpan.getData("span")) assertTrue(called) } @Test - fun `when finishSpan, a callback is called with the current span and the root call span is finished`() { + fun `when onEventFinish, a callback is called only once with the call span`() { val sut = fixture.getSut() var called = 0 - sut.startSpan("span") - sut.finishSpan("span") { - if (called == 0) { - assertEquals("http.client.span", it.operation) - assertEquals("${fixture.mockRequest.method} ${fixture.mockRequest.url}", it.description) - } else { - assertEquals(sut.callRootSpan, it) - } + sut.onEventStart("span") + sut.onEventFinish("span") { called++ - assertFalse(it.isFinished) } - assertEquals(2, called) + assertEquals(1, called) } @Test - fun `finishSpan is ignored if the span was not previously started`() { + fun `onEventFinish is ignored if the span was not previously started`() { val sut = fixture.getSut() var called = false - assertTrue(sut.getEventSpans().isEmpty()) - sut.finishSpan("span") { called = true } - assertTrue(sut.getEventSpans().isEmpty()) + assertTrue(sut.getEventDates().isEmpty()) + sut.onEventFinish("span") { called = true } + assertTrue(sut.getEventDates().isEmpty()) assertFalse(called) } @Test - fun `when finishEvent, a callback is called with the call root span before it is finished`() { + fun `when finish, a callback is called with the call span before it is finished`() { val sut = fixture.getSut() var called = false - sut.finishEvent { + sut.finish { called = true - assertEquals(sut.callRootSpan, it) + assertEquals(sut.callSpan, it) + assertFalse(it.isFinished) } assertTrue(called) } @Test - fun `when finishEvent, all running spans are finished`() { + fun `when finish, all event dates are cleared`() { val sut = fixture.getSut() - sut.startSpan("span") - val spans = sut.getEventSpans() - assertFalse(spans["span"]!!.isFinished) - sut.finishEvent() - assertTrue(spans["span"]!!.isFinished) + sut.onEventStart("span") + val dates = sut.getEventDates() + assertFalse(dates.isEmpty()) + sut.finish() + assertTrue(dates.isEmpty()) } @Test - fun `when finishEvent, a breadcrumb is captured with request in the hint`() { + fun `when finish, a breadcrumb is captured with request in the hint`() { val sut = fixture.getSut() - sut.finishEvent() + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertEquals(fixture.mockRequest.url.toString(), it.data["url"]) @@ -255,34 +235,21 @@ class SentryOkHttpEventTest { } @Test - fun `when finishEvent multiple times, only one breadcrumb is captured`() { + fun `when finish multiple times, only one breadcrumb is captured`() { val sut = fixture.getSut() - sut.finishEvent() - sut.finishEvent() + sut.finish() + sut.finish() verify(fixture.scopes, times(1)).addBreadcrumb(any(), any()) } @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() - assertTrue(spans["span"]!!.isFinished) - assertEquals(SpanStatus.OK, spans["span"]!!.status) - } - - @Test - fun `setResponse set protocol and code in the breadcrumb and root span, and response in the hint`() { + fun `setResponse set protocol and code in the breadcrumb and call span, and response in the hint`() { val sut = fixture.getSut() sut.setResponse(fixture.response) - assertEquals(fixture.response.protocol.name, sut.callRootSpan?.getData("protocol")) - assertEquals(fixture.response.code, sut.callRootSpan?.getData(SpanDataConvention.HTTP_STATUS_CODE_KEY)) - sut.finishEvent() + assertEquals(fixture.response.protocol.name, sut.callSpan?.getData("protocol")) + assertEquals(fixture.response.code, sut.callSpan?.getData(SpanDataConvention.HTTP_STATUS_CODE_KEY)) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { @@ -296,11 +263,11 @@ class SentryOkHttpEventTest { } @Test - fun `setProtocol set protocol in the breadcrumb and in the root span`() { + fun `setProtocol set protocol in the breadcrumb and in the call span`() { val sut = fixture.getSut() sut.setProtocol("protocol") - assertEquals("protocol", sut.callRootSpan?.getData("protocol")) - sut.finishEvent() + assertEquals("protocol", sut.callSpan?.getData("protocol")) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertEquals("protocol", it.data["protocol"]) @@ -313,8 +280,8 @@ class SentryOkHttpEventTest { fun `setProtocol is ignored if protocol is null`() { val sut = fixture.getSut() sut.setProtocol(null) - assertNull(sut.callRootSpan?.getData("protocol")) - sut.finishEvent() + assertNull(sut.callSpan?.getData("protocol")) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertNull(it.data["protocol"]) @@ -324,11 +291,11 @@ class SentryOkHttpEventTest { } @Test - fun `setRequestBodySize set RequestBodySize in the breadcrumb and in the root span`() { + fun `setRequestBodySize set RequestBodySize in the breadcrumb and in the call span`() { val sut = fixture.getSut() sut.setRequestBodySize(10) - assertEquals(10L, sut.callRootSpan?.getData("http.request_content_length")) - sut.finishEvent() + assertEquals(10L, sut.callSpan?.getData("http.request_content_length")) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertEquals(10L, it.data["request_content_length"]) @@ -341,8 +308,8 @@ class SentryOkHttpEventTest { fun `setRequestBodySize is ignored if RequestBodySize is negative`() { val sut = fixture.getSut() sut.setRequestBodySize(-1) - assertNull(sut.callRootSpan?.getData("http.request_content_length")) - sut.finishEvent() + assertNull(sut.callSpan?.getData("http.request_content_length")) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertNull(it.data["request_content_length"]) @@ -352,11 +319,11 @@ class SentryOkHttpEventTest { } @Test - fun `setResponseBodySize set ResponseBodySize in the breadcrumb and in the root span`() { + fun `setResponseBodySize set ResponseBodySize in the breadcrumb and in the call span`() { val sut = fixture.getSut() sut.setResponseBodySize(10) - assertEquals(10L, sut.callRootSpan?.getData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY)) - sut.finishEvent() + assertEquals(10L, sut.callSpan?.getData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY)) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertEquals(10L, it.data["response_content_length"]) @@ -369,8 +336,8 @@ class SentryOkHttpEventTest { fun `setResponseBodySize is ignored if ResponseBodySize is negative`() { val sut = fixture.getSut() sut.setResponseBodySize(-1) - assertNull(sut.callRootSpan?.getData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY)) - sut.finishEvent() + assertNull(sut.callSpan?.getData(SpanDataConvention.HTTP_RESPONSE_CONTENT_LENGTH_KEY)) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertNull(it.data["response_content_length"]) @@ -380,11 +347,11 @@ class SentryOkHttpEventTest { } @Test - fun `setError set success to false and errorMessage in the breadcrumb and in the root span`() { + fun `setError set success to false and errorMessage in the breadcrumb and in the call span`() { val sut = fixture.getSut() sut.setError("errorMessage") - assertEquals("errorMessage", sut.callRootSpan?.getData("error_message")) - sut.finishEvent() + assertEquals("errorMessage", sut.callSpan?.getData("error_message")) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertEquals("errorMessage", it.data["error_message"]) @@ -394,12 +361,12 @@ class SentryOkHttpEventTest { } @Test - fun `setError sets success to false in the breadcrumb and in the root span even if errorMessage is null`() { + fun `setError sets success to false in the breadcrumb and in the call span even if errorMessage is null`() { val sut = fixture.getSut() sut.setError(null) - assertNotNull(sut.callRootSpan) - assertNull(sut.callRootSpan.getData("error_message")) - sut.finishEvent() + assertNotNull(sut.callSpan) + assertNull(sut.callSpan.getData("error_message")) + sut.finish() verify(fixture.scopes).addBreadcrumb( check { assertNull(it.data["error_message"]) @@ -409,166 +376,14 @@ class SentryOkHttpEventTest { } @Test - fun `secureConnect span is child of connect span`() { - val sut = fixture.getSut() - sut.startSpan(CONNECT_EVENT) - sut.startSpan(SECURE_CONNECT_EVENT) - val spans = sut.getEventSpans() - val secureConnectSpan = spans[SECURE_CONNECT_EVENT] as Span? - val connectSpan = spans[CONNECT_EVENT] as Span? - assertNotNull(secureConnectSpan) - assertNotNull(connectSpan) - assertEquals(connectSpan.spanId, secureConnectSpan.parentSpanId) - } - - @Test - fun `secureConnect span is child of root span if connect span is not available`() { - val sut = fixture.getSut() - sut.startSpan(SECURE_CONNECT_EVENT) - val spans = sut.getEventSpans() - val rootSpan = sut.callRootSpan as Span? - val secureConnectSpan = spans[SECURE_CONNECT_EVENT] as Span? - assertNotNull(secureConnectSpan) - assertNotNull(rootSpan) - assertEquals(rootSpan.spanId, secureConnectSpan.parentSpanId) - } - - @Test - fun `request and response spans are children of connection span`() { - val sut = fixture.getSut() - sut.startSpan(CONNECTION_EVENT) - sut.startSpan(REQUEST_HEADERS_EVENT) - sut.startSpan(REQUEST_BODY_EVENT) - sut.startSpan(RESPONSE_HEADERS_EVENT) - sut.startSpan(RESPONSE_BODY_EVENT) - val spans = sut.getEventSpans() - val connectionSpan = spans[CONNECTION_EVENT] as Span? - val requestHeadersSpan = spans[REQUEST_HEADERS_EVENT] as Span? - val requestBodySpan = spans[REQUEST_BODY_EVENT] as Span? - val responseHeadersSpan = spans[RESPONSE_HEADERS_EVENT] as Span? - val responseBodySpan = spans[RESPONSE_BODY_EVENT] as Span? - assertNotNull(connectionSpan) - assertEquals(connectionSpan.spanId, requestHeadersSpan?.parentSpanId) - assertEquals(connectionSpan.spanId, requestBodySpan?.parentSpanId) - assertEquals(connectionSpan.spanId, responseHeadersSpan?.parentSpanId) - assertEquals(connectionSpan.spanId, responseBodySpan?.parentSpanId) - } - - @Test - fun `request and response spans are children of root span if connection span is not available`() { - val sut = fixture.getSut() - sut.startSpan(REQUEST_HEADERS_EVENT) - sut.startSpan(REQUEST_BODY_EVENT) - sut.startSpan(RESPONSE_HEADERS_EVENT) - sut.startSpan(RESPONSE_BODY_EVENT) - val spans = sut.getEventSpans() - val connectionSpan = spans[CONNECTION_EVENT] as Span? - val requestHeadersSpan = spans[REQUEST_HEADERS_EVENT] as Span? - val requestBodySpan = spans[REQUEST_BODY_EVENT] as Span? - val responseHeadersSpan = spans[RESPONSE_HEADERS_EVENT] as Span? - val responseBodySpan = spans[RESPONSE_BODY_EVENT] as Span? - val rootSpan = sut.callRootSpan as Span? - assertNotNull(rootSpan) - assertNull(connectionSpan) - assertEquals(rootSpan.spanId, requestHeadersSpan?.parentSpanId) - assertEquals(rootSpan.spanId, requestBodySpan?.parentSpanId) - assertEquals(rootSpan.spanId, responseHeadersSpan?.parentSpanId) - 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) - sut.finishEvent() - 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) - } - - @Test - fun `finishEvent moves throwables from inner span to call root span`() { - val sut = fixture.getSut() - val throwable = RuntimeException() - sut.startSpan(CONNECTION_EVENT) - sut.startSpan("random event") - sut.finishSpan("random event") { it.status = SpanStatus.DEADLINE_EXCEEDED } - sut.finishSpan(CONNECTION_EVENT) { - it.status = SpanStatus.INTERNAL_ERROR - it.throwable = throwable - } - sut.finishEvent() - val spans = sut.getEventSpans() - val connectionSpan = spans[CONNECTION_EVENT] as Span? - val randomEventSpan = spans["random event"] as Span? - assertNotNull(connectionSpan) - assertNotNull(randomEventSpan) - // randomEventSpan was finished with DEADLINE_EXCEEDED - assertEquals(SpanStatus.DEADLINE_EXCEEDED, randomEventSpan.status) - // connectionSpan was finished with INTERNAL_ERROR - assertEquals(SpanStatus.INTERNAL_ERROR, connectionSpan.status) - - // connectionSpan was finished last with INTERNAL_ERROR and a throwable, and it's moved to the root call - assertEquals(SpanStatus.INTERNAL_ERROR, sut.callRootSpan!!.status) - assertEquals(throwable, sut.callRootSpan.throwable) - assertNull(connectionSpan.throwable) - } - - @Test - fun `scheduleFinish schedules finishEvent and finish running spans to specific timestamp`() { - fixture.scopes.options.executorService = ImmediateExecutorService() - val sut = spy(fixture.getSut()) - val timestamp = mock() - sut.startSpan(CONNECTION_EVENT) - sut.scheduleFinish(timestamp) - verify(sut).finishEvent(eq(timestamp), anyOrNull()) - val spans = sut.getEventSpans() - assertEquals(timestamp, spans[CONNECTION_EVENT]?.finishDate) - } - - @Test - fun `finishEvent with timestamp trims call root span`() { - val sut = fixture.getSut() - val timestamp = mock() - sut.finishEvent(finishDate = timestamp) - assertEquals(timestamp, sut.callRootSpan!!.finishDate) - } - - @Test - fun `scheduleFinish does not throw if executor is shut down`() { - val executorService = mock() - whenever(executorService.schedule(any(), any())).thenThrow(RejectedExecutionException()) - whenever(fixture.scopes.options).thenReturn(SentryOptions().apply { this.executorService = executorService }) - val sut = fixture.getSut() - sut.scheduleFinish(mock()) - } - - @Test - fun `setClientErrorResponse will capture the client error on finishEvent`() { + fun `setClientErrorResponse will capture the client error on finish`() { val sut = fixture.getSut() val clientErrorResponse = mock() whenever(clientErrorResponse.request).thenReturn(fixture.mockRequest) sut.setClientErrorResponse(clientErrorResponse) verify(fixture.scopes, never()).captureEvent(any(), any()) - sut.finishEvent() - assertNotNull(sut.callRootSpan) + sut.finish() + assertNotNull(sut.callSpan) verify(fixture.scopes).captureEvent( argThat { throwable is SentryHttpClientException && @@ -582,14 +397,14 @@ class SentryOkHttpEventTest { } @Test - fun `setClientErrorResponse will capture the client error on finishEvent even when no span is running`() { + fun `setClientErrorResponse will capture the client error on finish even when no span is running`() { val sut = fixture.getSut(currentSpan = null) val clientErrorResponse = mock() whenever(clientErrorResponse.request).thenReturn(fixture.mockRequest) sut.setClientErrorResponse(clientErrorResponse) verify(fixture.scopes, never()).captureEvent(any(), any()) - sut.finishEvent() - assertNull(sut.callRootSpan) + sut.finish() + assertNull(sut.callSpan) verify(fixture.scopes).captureEvent( argThat { throwable is SentryHttpClientException && @@ -605,10 +420,10 @@ class SentryOkHttpEventTest { @Test fun `when setClientErrorResponse is not called, no client error is captured`() { val sut = fixture.getSut() - sut.finishEvent() + sut.finish() verify(fixture.scopes, never()).captureEvent(any(), any()) } /** Retrieve all the spans started in the event using reflection. */ - private fun SentryOkHttpEvent.getEventSpans() = getProperty>("eventSpans") + private fun SentryOkHttpEvent.getEventDates() = getProperty>("eventDates") } diff --git a/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpInterceptorTest.kt b/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpInterceptorTest.kt index f40b2c4cb5..8d2feff06e 100644 --- a/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpInterceptorTest.kt +++ b/sentry-okhttp/src/test/java/io/sentry/okhttp/SentryOkHttpInterceptorTest.kt @@ -13,6 +13,7 @@ import io.sentry.ScopeCallback import io.sentry.SentryOptions import io.sentry.SentryTraceHeader import io.sentry.SentryTracer +import io.sentry.Span import io.sentry.SpanDataConvention import io.sentry.SpanStatus import io.sentry.TransactionContext @@ -584,4 +585,16 @@ class SentryOkHttpInterceptorTest { call.execute() verify(fixture.scopes, never()).captureEvent(any(), any()) } + + @Test + fun `when a call is captured by SentryOkHttpEventListener, interceptor finishes event`() { + val sut = fixture.getSut() + val call = sut.newCall(getRequest()) + val event = mock() + val span = Span(mock(), fixture.sentryTracer, fixture.scopes, mock()) + whenever(event.callSpan).thenReturn(span) + SentryOkHttpEventListener.eventMap[call] = event + call.execute() + verify(event).finish() + } }