From b7b4bc1d144583f9417df36736a1ec4ea480f6e2 Mon Sep 17 00:00:00 2001 From: Miguel Juarez Lopez Date: Fri, 6 Dec 2024 17:21:35 -0500 Subject: [PATCH] Augment http logs with extra fields for gql requests --- .../apollo3/CaptureApollo3Interceptor.kt | 71 ------------------- .../apollo3/CaptureApolloInterceptor.kt | 53 ++++++++++++++ .../capture/network/HttpRequestInfo.kt | 29 +++++++- .../CaptureOkHttpEventListenerFactoryTest.kt | 57 +++++++++++++++ .../bitdrift/gradletestapp/FirstFragment.kt | 13 ++-- 5 files changed, 147 insertions(+), 76 deletions(-) delete mode 100644 platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApollo3Interceptor.kt create mode 100644 platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApolloInterceptor.kt diff --git a/platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApollo3Interceptor.kt b/platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApollo3Interceptor.kt deleted file mode 100644 index 3a37175e..00000000 --- a/platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApollo3Interceptor.kt +++ /dev/null @@ -1,71 +0,0 @@ -// capture-sdk - bitdrift's client SDK -// Copyright Bitdrift, Inc. All rights reserved. -// -// Use of this source code is governed by a source available license that can be found in the -// LICENSE file or at: -// https://polyformproject.org/wp-content/uploads/2020/06/PolyForm-Shield-1.0.0.txt - -package io.bitdrift.capture.apollo3 - -import com.apollographql.apollo3.api.ApolloRequest -import com.apollographql.apollo3.api.ApolloResponse -import com.apollographql.apollo3.api.CustomScalarAdapters -import com.apollographql.apollo3.api.Mutation -import com.apollographql.apollo3.api.Operation -import com.apollographql.apollo3.api.Query -import com.apollographql.apollo3.api.Subscription -import com.apollographql.apollo3.api.variables -import com.apollographql.apollo3.interceptor.ApolloInterceptor -import com.apollographql.apollo3.interceptor.ApolloInterceptorChain -import io.bitdrift.capture.Capture -import io.bitdrift.capture.ILogger -import io.bitdrift.capture.LogLevel -import io.bitdrift.capture.events.span.SpanResult -import kotlinx.coroutines.flow.Flow -import kotlinx.coroutines.flow.onEach - -/** - * An [ApolloInterceptor] that logs request and response events to the [Capture.Logger]. - */ -class CaptureApollo3Interceptor internal constructor(private val internalLogger: ILogger?) : ApolloInterceptor { - - constructor() : this(Capture.logger()) - - // attempts to get the latest logger if one wasn't found at construction time - private val logger: ILogger? - get() = internalLogger ?: Capture.logger() - - override fun intercept(request: ApolloRequest, chain: ApolloInterceptorChain): Flow> { - val requestFields = buildMap { - put("_operation_type", request.operation.type()) - put("_operation_name", request.operation.name()) - request.scalarAdapters?.let { - put("_operation_variables", request.operation.variables(it).valueMap.toString()) - } - } - val graphqlSpan = logger?.startSpan("_graphql", LogLevel.DEBUG, requestFields) // use "reserved" magic string - - return chain.proceed(request).onEach { response -> - if (!response.hasErrors()) { - graphqlSpan?.end(SpanResult.SUCCESS) - } else { - graphqlSpan?.end( - SpanResult.FAILURE, - mapOf("_graphql_errors" to (response.errors?.joinToString("|") ?: "none")) - ) - } - } - } - - private fun Operation.type(): String { - return when (this) { - is Query -> "query" - is Mutation -> "mutation" - is Subscription -> "subscription" - else -> this.javaClass.simpleName - } - } - - private val ApolloRequest.scalarAdapters - get() = executionContext[CustomScalarAdapters] -} diff --git a/platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApolloInterceptor.kt b/platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApolloInterceptor.kt new file mode 100644 index 00000000..797b8656 --- /dev/null +++ b/platform/jvm/capture-apollo3/src/main/kotlin/io/bitdrift/capture/apollo3/CaptureApolloInterceptor.kt @@ -0,0 +1,53 @@ +// capture-sdk - bitdrift's client SDK +// Copyright Bitdrift, Inc. All rights reserved. +// +// Use of this source code is governed by a source available license that can be found in the +// LICENSE file or at: +// https://polyformproject.org/wp-content/uploads/2020/06/PolyForm-Shield-1.0.0.txt + +package io.bitdrift.capture.apollo3 + +import com.apollographql.apollo3.api.ApolloRequest +import com.apollographql.apollo3.api.ApolloResponse +import com.apollographql.apollo3.api.Mutation +import com.apollographql.apollo3.api.Operation +import com.apollographql.apollo3.api.Query +import com.apollographql.apollo3.api.Subscription +import com.apollographql.apollo3.interceptor.ApolloInterceptor +import com.apollographql.apollo3.interceptor.ApolloInterceptorChain +import io.bitdrift.capture.Capture +import kotlinx.coroutines.flow.Flow + +/** + * An [ApolloInterceptor] that logs request and response events to the [Capture.Logger]. + */ +class CaptureApolloInterceptor: ApolloInterceptor { + + override fun intercept(request: ApolloRequest, chain: ApolloInterceptorChain): Flow> { + // Use special header format that is recognized by the CaptureOkHttpEventListener to be transformed into a span + val requestBuilder = request.newBuilder() + .addHttpHeader("x-capture-span-key", "gql") + .addHttpHeader("x-capture-span-gql-name", "graphql") + .addHttpHeader("x-capture-span-gql-field-operation-name", request.operation.name()) + .addHttpHeader("x-capture-span-gql-field-operation-id", request.operation.id()) + .addHttpHeader("x-capture-span-gql-field-operation-type", request.operation.type()) + // TODO(murki): Augment with + // request.executionContext[CustomScalarAdapters]?.let { + // addHttpHeader("x-capture-span-gql-field-operation-variables", request.operation.variables(it).valueMap.toString()) + // } + + val modifiedRequest = requestBuilder.build() + + // TODO(murki): Augment response logs with response.errors + return chain.proceed(modifiedRequest) + } + + private fun Operation.type(): String { + return when (this) { + is Query -> "query" + is Mutation -> "mutation" + is Subscription -> "subscription" + else -> this.javaClass.simpleName + } + } +} diff --git a/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/network/HttpRequestInfo.kt b/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/network/HttpRequestInfo.kt index bc8cba46..50a9aa63 100644 --- a/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/network/HttpRequestInfo.kt +++ b/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/network/HttpRequestInfo.kt @@ -46,8 +46,8 @@ data class HttpRequestInfo @JvmOverloads constructor( internal val commonFields: InternalFieldsMap by lazy { extraFields.toFields() + buildMap { + putOptionalHeaderSpanFields(headers) put(SpanField.Key.ID, FieldValue.StringField(spanId.toString())) - put(SpanField.Key.NAME, FieldValue.StringField("_http")) put(SpanField.Key.TYPE, FieldValue.StringField(SpanField.Value.TYPE_START)) put("_method", FieldValue.StringField(method)) putOptional(HttpFieldKey.HOST, host) @@ -62,4 +62,31 @@ data class HttpRequestInfo @JvmOverloads constructor( } internal val matchingFields: InternalFieldsMap = headers?.let { HTTPHeaders.normalizeHeaders(it) }.toFields() + + /** + * Adds optional fields to the mutable map based on the provided headers. + * + * This function checks for the presence of the "x-capture-span-key" header. + * If the header is present, it constructs a span name and additional fields from other headers + * and adds them to the map. If the header is not present, it adds a default span name. + * + * @param headers The map of headers from which fields are extracted. + */ + private fun MutableMap.putOptionalHeaderSpanFields(headers: Map?) { + headers?.get("x-capture-span-key")?.let { spanKey -> + val prefix = "x-capture-span-$spanKey" + val spanName = headers["$prefix-name"] ?: "" + put(SpanField.Key.NAME, FieldValue.StringField(spanName)) + val fieldPrefix = "$prefix-field" + headers.forEach { (key, value) -> + if (key.startsWith(fieldPrefix)) { + val fieldKey = key.removePrefix(fieldPrefix).replace('-', '_') + put(fieldKey, FieldValue.StringField(value)) + } + } + } ?: run { + // Default span name is simply http + put(SpanField.Key.NAME, FieldValue.StringField("_http")) + } + } } diff --git a/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/CaptureOkHttpEventListenerFactoryTest.kt b/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/CaptureOkHttpEventListenerFactoryTest.kt index 367f583b..6f5d8447 100644 --- a/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/CaptureOkHttpEventListenerFactoryTest.kt +++ b/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/CaptureOkHttpEventListenerFactoryTest.kt @@ -8,7 +8,9 @@ package io.bitdrift.capture import com.nhaarman.mockitokotlin2.any +import com.nhaarman.mockitokotlin2.argThat import com.nhaarman.mockitokotlin2.argumentCaptor +import com.nhaarman.mockitokotlin2.eq import com.nhaarman.mockitokotlin2.mock import com.nhaarman.mockitokotlin2.verify import com.nhaarman.mockitokotlin2.whenever @@ -17,6 +19,7 @@ import io.bitdrift.capture.network.HttpRequestInfo import io.bitdrift.capture.network.HttpResponseInfo import io.bitdrift.capture.network.okhttp.CaptureOkHttpEventListenerFactory import okhttp3.Call +import okhttp3.Headers.Companion.toHeaders import okhttp3.Protocol import okhttp3.Request import okhttp3.RequestBody.Companion.toRequestBody @@ -336,4 +339,58 @@ class CaptureOkHttpEventListenerFactoryTest { assertThat(httpResponseInfo.fields["_error_type"].toString()).isEqualTo(err::javaClass.get().simpleName) assertThat(httpResponseInfo.fields["_error_message"].toString()).isEqualTo(errorMessage) } + + @Test + fun testExtraHeadersSendCustomSpans() { + // ARRANGE + val headerFields = mapOf( + "x-capture-span-key" to "gql", + "x-capture-span-gql-name" to "mySpanName", + "x-capture-span-gql-field-operation-name" to "myOperationName", + "x-capture-span-gql-field-operation-id" to "myOperationId", + "x-capture-span-gql-field-operation-type" to "query", + ) +// val expectedSpanName = "_mySpanName" +// val expectedFields = mapOf( +// "_operation_name" to "myOperationName", +// "_operation_id" to "myOperationId", +// "_operation_type" to "query", +// ) + + val request = Request.Builder() + .url(endpoint) + .post("test".toRequestBody()) + .headers(headerFields.toHeaders()) + .build() + val call: Call = mock() + whenever(call.request()).thenReturn(request) + + // ACT + val factory = CaptureOkHttpEventListenerFactory(null, logger, clock) + val listener = factory.create(call) + + listener.callStart(call) + +// listener.requestHeadersEnd(call, request) +// listener.requestBodyEnd(call, 4) +// +// listener.responseHeadersEnd(call, response) +// listener.responseBodyEnd(call, 234) +// +// listener.callEnd(call) + + // ASSERT +// verify(logger).startSpan(eq(expectedSpanName), eq(LogLevel.DEBUG), argThat { this.entries.containsAll(expectedFields.entries) }) + val httpRequestInfoCapture = argumentCaptor() + verify(logger).log(httpRequestInfoCapture.capture()) +// val httpResponseInfoCapture = argumentCaptor() +// verify(logger).log(httpResponseInfoCapture.capture()) + + val httpRequestInfo = httpRequestInfoCapture.firstValue +// val httpResponseInfo = httpResponseInfoCapture.firstValue + + assertThat(httpRequestInfo.fields["_operation_name"].toString()).isEqualTo("myOperationName") +// assertThat(httpResponseInfo.fields["_path"].toString()) +// .isEqualTo(httpRequestInfo.fields["_path"].toString()) + } } diff --git a/platform/jvm/gradle-test-app/src/main/java/io/bitdrift/gradletestapp/FirstFragment.kt b/platform/jvm/gradle-test-app/src/main/java/io/bitdrift/gradletestapp/FirstFragment.kt index 0cb96736..49c0ae60 100644 --- a/platform/jvm/gradle-test-app/src/main/java/io/bitdrift/gradletestapp/FirstFragment.kt +++ b/platform/jvm/gradle-test-app/src/main/java/io/bitdrift/gradletestapp/FirstFragment.kt @@ -36,7 +36,7 @@ import io.bitdrift.capture.Capture.Logger import io.bitdrift.capture.CaptureJniLibrary import io.bitdrift.capture.LogLevel import io.bitdrift.capture.LoggerImpl -import io.bitdrift.capture.apollo3.CaptureApollo3Interceptor +import io.bitdrift.capture.apollo3.CaptureApolloInterceptor import io.bitdrift.capture.network.okhttp.CaptureOkHttpEventListenerFactory import io.bitdrift.gradletestapp.databinding.FragmentFirstBinding import kotlinx.coroutines.MainScope @@ -154,7 +154,7 @@ class FirstFragment : Fragment() { private fun provideApolloClient(): ApolloClient { return ApolloClient.Builder() .serverUrl("https://apollo-fullstack-tutorial.herokuapp.com/graphql") - .addInterceptor(CaptureApollo3Interceptor()) + .addInterceptor(CaptureApolloInterceptor()) .build() } @@ -223,8 +223,13 @@ class FirstFragment : Fragment() { private fun performGraphQlRequest(view: View) { MainScope().launch { - val response = apolloClient.query(LaunchListQuery()).execute() - Logger.logDebug(mapOf("response_data" to response.data.toString())) { "GraphQL response data received" } + try { + val response = apolloClient.query(LaunchListQuery()).execute() +// Logger.logDebug(mapOf("response_headers" to response.executionContext[HttpInfo]?.headers.toString())) { "GraphQL response headers received" } + Logger.logDebug(mapOf("response_data" to response.data.toString())) { "GraphQL response data received" } + } catch (e: Exception) { + Timber.e(e, "GraphQL request failed") + } } }