From 12914388413ca8958c7d0b737cf0df06d9a3c83a Mon Sep 17 00:00:00 2001 From: mendezm <141789731+kailyak@users.noreply.github.com> Date: Mon, 15 Apr 2024 09:06:34 -0700 Subject: [PATCH] Add graphql query request and resoponse sizes --- .../build.gradle.kts | 2 + .../netflix/graphql/dgs/metrics/DgsMetrics.kt | 12 ++ .../DgsGraphQLMetricsInstrumentation.kt | 86 +++++++++++++ .../micrometer/MicrometerServletSmokeTest.kt | 118 ++++++++++++++++-- 4 files changed, 207 insertions(+), 11 deletions(-) diff --git a/graphql-dgs-spring-boot-micrometer/build.gradle.kts b/graphql-dgs-spring-boot-micrometer/build.gradle.kts index d9e9f5840..cb617e124 100644 --- a/graphql-dgs-spring-boot-micrometer/build.gradle.kts +++ b/graphql-dgs-spring-boot-micrometer/build.gradle.kts @@ -7,6 +7,8 @@ dependencies { implementation("com.netflix.spectator:spectator-api:1.7.+") implementation("com.github.ben-manes.caffeine:caffeine") implementation("org.springframework:spring-context-support") + implementation("org.jetbrains.kotlinx:kotlinx-coroutines-core") + implementation("com.fasterxml.jackson.module:jackson-module-kotlin") compileOnly(project(":graphql-dgs-spring-boot-starter")) compileOnly("org.springframework.boot:spring-boot-actuator-autoconfigure") diff --git a/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/DgsMetrics.kt b/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/DgsMetrics.kt index 7474c84fb..c843dcbca 100644 --- a/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/DgsMetrics.kt +++ b/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/DgsMetrics.kt @@ -41,6 +41,18 @@ object DgsMetrics { * This is useful if you want to find data loaders that might be responsible for poor query performance. */ DATA_LOADER("gql.dataLoader"), + + /** + * _DistributionSummary_ that captures the size of a graphql query in a request. + * Measures size in bytes of the query and variables. + */ + QUERY_REQUEST_SIZE("gql.query.request.size"), + + /** + * _DistributionSummary_ that captures the size of the result of a graphql query returned in a response. + * Measures size in bytes of the data, errors, and extensions. + */ + QUERY_RESPONSE_SIZE("gql.query.response.size"), } /** Defines the tags applied to the [GqlMetric] emitted by the framework. */ diff --git a/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/micrometer/DgsGraphQLMetricsInstrumentation.kt b/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/micrometer/DgsGraphQLMetricsInstrumentation.kt index a376dbb5a..d12433692 100644 --- a/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/micrometer/DgsGraphQLMetricsInstrumentation.kt +++ b/graphql-dgs-spring-boot-micrometer/src/main/kotlin/com/netflix/graphql/dgs/metrics/micrometer/DgsGraphQLMetricsInstrumentation.kt @@ -1,5 +1,7 @@ package com.netflix.graphql.dgs.metrics.micrometer +import com.fasterxml.jackson.databind.ObjectMapper +import com.fasterxml.jackson.module.kotlin.kotlinModule import com.netflix.graphql.dgs.Internal import com.netflix.graphql.dgs.internal.DgsSchemaProvider import com.netflix.graphql.dgs.metrics.DgsMetrics.GqlMetric @@ -29,16 +31,27 @@ import graphql.schema.DataFetcher import graphql.schema.GraphQLNamedType import graphql.schema.GraphQLTypeUtil import graphql.validation.ValidationError +import io.micrometer.core.instrument.DistributionSummary import io.micrometer.core.instrument.MeterRegistry import io.micrometer.core.instrument.Tag import io.micrometer.core.instrument.Timer import org.slf4j.Logger import org.slf4j.LoggerFactory import org.springframework.boot.actuate.metrics.AutoTimer +import org.springframework.http.converter.json.Jackson2ObjectMapperBuilder +import java.io.ByteArrayOutputStream import java.util.Optional import java.util.concurrent.CompletableFuture import java.util.concurrent.CompletionStage import kotlin.jvm.optionals.getOrNull +import kotlinx.coroutines.CoroutineName +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.Deferred +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.SupervisorJob +import kotlinx.coroutines.async +import kotlinx.coroutines.coroutineScope +import kotlinx.coroutines.launch class DgsGraphQLMetricsInstrumentation( private val schemaProvider: DgsSchemaProvider, @@ -52,6 +65,8 @@ class DgsGraphQLMetricsInstrumentation( companion object { private val log: Logger = LoggerFactory.getLogger(DgsGraphQLMetricsInstrumentation::class.java) + private val applicationScope = CoroutineScope(SupervisorJob() + Dispatchers.Default) + private val mapper: ObjectMapper = Jackson2ObjectMapperBuilder().modules(kotlinModule()).build() } @Deprecated("Deprecated in Java") @@ -93,6 +108,14 @@ class DgsGraphQLMetricsInstrumentation( ): CompletableFuture { require(state is MetricsInstrumentationState) + try { + applicationScope.launch(CoroutineName("captureGqlQueryResponseSizeMetric-${state.operationNameValue}")) { + captureGqlQueryResponseSizeMetric(executionResult, parameters, state) + } + } catch (exc: Exception) { + log.warn("Exception thrown while attempting to serialize and measure response size of graphql data.") + } + val errorTagValues = ErrorUtils.sanitizeErrorPaths(executionResult) if (errorTagValues.isNotEmpty()) { val baseTags = buildList { @@ -204,6 +227,15 @@ class DgsGraphQLMetricsInstrumentation( if (properties.tags.complexity.enabled) { state.queryComplexityValue = ComplexityUtils.resolveComplexity(parameters) } + + try { + applicationScope.launch(CoroutineName("captureGqlQueryRequestSizeMetric-${state.operationNameValue}")) { + captureGqlQueryRequestSizeMetric(parameters.executionContext.executionInput, state) + } + } catch (exc: Exception) { + log.warn("Exception thrown while attempting to serialize and measure request size of graphql data.") + } + return super.beginExecuteOperation(parameters, state) } @@ -225,6 +257,51 @@ class DgsGraphQLMetricsInstrumentation( ) } + private suspend fun captureGqlQueryRequestSizeMetric(executionInput: ExecutionInput, + state: MetricsInstrumentationState) = coroutineScope { + val tags = buildList { addAll(state.tags()) } + + val requestSizeMeter = DistributionSummary.builder(GqlMetric.QUERY_REQUEST_SIZE.key) + .description("Tracks graphql query request size.") + .baseUnit("bytes") + .tags(tags) + .publishPercentiles(0.90, 0.95, 0.99) + .register(registrySupplier.get()) + + launch { + val gqlQuerySize: Deferred = async { MeasurementUtils.serializeAndMeasureSize(executionInput.query) } + val gqlVariablesSize: Deferred = async { MeasurementUtils.serializeAndMeasureSize(executionInput.rawVariables) } + + val totalSize = gqlQuerySize.await() + gqlVariablesSize.await() + + requestSizeMeter.record(totalSize.toDouble()) + } + } + + private suspend fun captureGqlQueryResponseSizeMetric(executionResult: ExecutionResult, parameters: InstrumentationExecutionParameters, + state: MetricsInstrumentationState) = coroutineScope { + val tags = buildList { + addAll(state.tags()) + addAll(tagsProvider.getExecutionTags(state, parameters, executionResult, null)) + } + + val responseSizeMeter = DistributionSummary.builder(GqlMetric.QUERY_RESPONSE_SIZE.key) + .description("Tracks graphql query response size.") + .baseUnit("bytes") + .tags(tags) + .publishPercentiles(0.90, 0.95, 0.99) + .register(registrySupplier.get()) + + launch { + val gqlDataSize: Deferred = async { MeasurementUtils.serializeAndMeasureSize(executionResult.getData>()) } + val gqlErrorsSize: Deferred = async { MeasurementUtils.serializeAndMeasureSize(executionResult.errors) } + val gqlExtensionsSize: Deferred = async { MeasurementUtils.serializeAndMeasureSize(executionResult.extensions) } + + val totalSize = gqlDataSize.await() + gqlErrorsSize.await() + gqlExtensionsSize.await() + responseSizeMeter.record(totalSize.toDouble()) + } + } + class MetricsInstrumentationState( private val registry: MeterRegistry, private val limitedTagMetricResolver: LimitedTagMetricResolver @@ -382,4 +459,13 @@ class DgsGraphQLMetricsInstrumentation( internal data class ErrorTagValues(val path: String, val type: String, val detail: String) } + + internal object MeasurementUtils { + suspend inline fun serializeAndMeasureSize(obj: T): Int = coroutineScope { + ByteArrayOutputStream().use { outputStream -> + mapper.writeValue(outputStream, obj) + outputStream.size() + } + } + } } diff --git a/graphql-dgs-spring-boot-micrometer/src/test/kotlin/com/netflix/graphql/dgs/metrics/micrometer/MicrometerServletSmokeTest.kt b/graphql-dgs-spring-boot-micrometer/src/test/kotlin/com/netflix/graphql/dgs/metrics/micrometer/MicrometerServletSmokeTest.kt index 2afeb3f71..928cfbe52 100644 --- a/graphql-dgs-spring-boot-micrometer/src/test/kotlin/com/netflix/graphql/dgs/metrics/micrometer/MicrometerServletSmokeTest.kt +++ b/graphql-dgs-spring-boot-micrometer/src/test/kotlin/com/netflix/graphql/dgs/metrics/micrometer/MicrometerServletSmokeTest.kt @@ -123,7 +123,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters() - assertThat(meters).containsOnlyKeys("gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.query", "gql.resolver") assertThat(meters["gql.query"]).isNotNull.hasSize(1) assertThat(meters["gql.query"]?.first()?.id?.tags) @@ -165,7 +165,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters() - assertThat(meters).containsOnlyKeys("gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.query", "gql.resolver") assertThat(meters["gql.query"]).isNotNull.hasSize(1) assertThat(meters["gql.query"]?.first()?.id?.tags) @@ -214,7 +214,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters() - assertThat(meters).containsOnlyKeys("gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.query", "gql.resolver") assertThat(meters["gql.query"]).isNotNull.hasSize(1) assertThat(meters["gql.query"]?.first()?.id?.tags) @@ -283,7 +283,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters() - assertThat(meters).containsOnlyKeys("gql.dataLoader", "gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.dataLoader", "gql.query", "gql.resolver") assertThat(meters["gql.dataLoader"]).isNotNull.hasSize(2) assertThat(meters["gql.dataLoader"]?.map { it.id.tags }) @@ -362,7 +362,7 @@ class MicrometerServletSmokeTest { ) val meters = fetchMeters("gql.") - assertThat(meters).containsOnlyKeys("gql.error", "gql.query") + assertThat(meters).containsKeys("gql.error", "gql.query") assertThat(meters["gql.error"]).isNotNull.hasSize(1) assertThat((meters["gql.error"]?.first() as CumulativeCounter).count()).isEqualTo(1.0) @@ -405,7 +405,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters() - assertThat(meters).containsOnlyKeys("gql.query") + assertThat(meters).containsKeys("gql.query") assertThat(meters["gql.query"]).isNotNull.hasSize(1) assertThat(meters["gql.query"]?.first()?.id?.tags) @@ -450,7 +450,7 @@ class MicrometerServletSmokeTest { ) val meters = fetchMeters("gql.") - assertThat(meters).containsOnlyKeys("gql.error", "gql.query") + assertThat(meters).containsKeys("gql.error", "gql.query") assertThat(meters["gql.error"]).isNotNull.hasSize(1) assertThat((meters["gql.error"]?.first() as CumulativeCounter).count()).isEqualTo(1.0) @@ -510,7 +510,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters("gql.") - assertThat(meters).containsOnlyKeys("gql.error", "gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.error", "gql.query", "gql.resolver") logMeters(meters["gql.error"]) assertThat(meters["gql.error"]).isNotNull.hasSizeGreaterThanOrEqualTo(1) @@ -583,7 +583,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters("gql.") - assertThat(meters).containsOnlyKeys("gql.error", "gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.error", "gql.query", "gql.resolver") assertThat(meters["gql.error"]).isNotNull.hasSizeGreaterThanOrEqualTo(1) assertThat((meters["gql.error"]?.first() as CumulativeCounter).count()).isEqualTo(1.0) @@ -655,7 +655,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters() - assertThat(meters).containsOnlyKeys("gql.error", "gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.error", "gql.query", "gql.resolver") assertThat(meters["gql.error"]).isNotNull.hasSizeGreaterThanOrEqualTo(1) assertThat((meters["gql.error"]?.first() as CumulativeCounter).count()).isEqualTo(1.0) @@ -723,7 +723,7 @@ class MicrometerServletSmokeTest { val meters = fetchMeters() - assertThat(meters).containsOnlyKeys("gql.error", "gql.query", "gql.resolver") + assertThat(meters).containsKeys("gql.error", "gql.query", "gql.resolver") assertThat(meters["gql.query"]).hasSizeGreaterThanOrEqualTo(1) assertThat(meters["gql.error"]).hasSizeGreaterThanOrEqualTo(3) @@ -767,6 +767,102 @@ class MicrometerServletSmokeTest { ) } + @Test + fun `Query input size metrics for a successful graphql request`() { + mvc.perform( + MockMvcRequestBuilders + .post("/graphql") + .contentType(MediaType.APPLICATION_JSON) + .content("""{ "query": "query my_op_1{ping}" }""") + ).andExpect(status().isOk) + .andExpect(content().json("""{"data":{"ping":"pong"}}""", false)) + + val meters = fetchMeters() + + // Check metrics are present. + assertThat(meters).containsKeys( + "gql.query.request.size", "gql.query.request.size.percentile", + "gql.query.response.size", "gql.query.response.size.percentile" + ) + + // Check expected percentiles: .90, .95, .99 + assertThat(meters["gql.query.request.size.percentile"]).isNotNull + assertThat(meters["gql.query.response.size.percentile"]).isNotNull + + // Check metric name and expected tags. + assertThat(meters["gql.query.request.size"]).isNotNull + assertThat(meters["gql.query.request.size"]?.first()?.id?.tags) + .containsAll( + Tags.of("gql.operation", "QUERY") + .and("gql.operation.name", "my_op_1") + .and("gql.query.complexity", "5") + .and("gql.query.sig.hash", MOCKED_QUERY_SIGNATURE.hash) + ) + + assertThat(meters["gql.query.response.size"]).isNotNull + assertThat(meters["gql.query.response.size"]?.first()?.id?.tags) + .containsAll( + Tags.of("outcome", "success") + .and("gql.operation", "QUERY") + .and("gql.operation.name", "my_op_1") + .and("gql.query.complexity", "5") + .and("gql.query.sig.hash", MOCKED_QUERY_SIGNATURE.hash) + ) + } + + @Test + fun `Query input size metrics for a unsuccessful graphql request`() { + mvc.perform( + MockMvcRequestBuilders + .post("/graphql") + .contentType(MediaType.APPLICATION_JSON) + .content("""{ "query": "{triggerBadRequestFailure}" }""") + ).andExpect(status().isOk) + .andExpect( + content().json( + """ + |{ + | "errors":[ + | {"message":"Exception triggered.", + | "locations":[],"path":["triggerBadRequestFailure"], + | "extensions":{"errorType":"BAD_REQUEST"}} + | ], + | "data":{"triggerBadRequestFailure":null} + |} + """.trimMargin(), + false + ) + ) + + val meters = fetchMeters() + + // Check metrics are present. + assertThat(meters).containsKeys( + "gql.query.request.size", "gql.query.request.size.percentile", + "gql.query.response.size", "gql.query.response.size.percentile" + ) + + // Check metric name and expected tags. + assertThat(meters["gql.query.request.size"]).isNotNull + assertThat(meters["gql.query.request.size"]?.first()?.id?.tags) + .containsAll( + Tags.of("gql.operation", "QUERY") + .and("gql.operation.name", "anonymous") + .and("gql.query.complexity", "5") + .and("gql.query.sig.hash", MOCKED_QUERY_SIGNATURE.hash) + ) + + assertThat(meters["gql.query.response.size"]).isNotNull + assertThat(meters["gql.query.response.size"]?.first()?.id?.tags) + .containsAll( + Tags.of("outcome", "failure") + .and("gql.operation", "QUERY") + .and("gql.operation.name", "anonymous") + .and("gql.query.complexity", "5") + .and("gql.query.sig.hash", MOCKED_QUERY_SIGNATURE.hash) + ) + } + private fun fetchMeters(prefix: String = "gql."): Map> { return meterRegistry.meters .asSequence()