From 67c9361c4571778a5c0b91154c1e84e8af2a7e05 Mon Sep 17 00:00:00 2001 From: Marc-Andre Giroux Date: Fri, 24 May 2024 10:09:43 -0400 Subject: [PATCH 01/15] use std mutex for query analysis cache, use spawn_blocking for parsing --- .../src/services/layers/query_analysis.rs | 74 ++++++++++++------- 1 file changed, 48 insertions(+), 26 deletions(-) diff --git a/apollo-router/src/services/layers/query_analysis.rs b/apollo-router/src/services/layers/query_analysis.rs index 70dc9c50b0..660660c93a 100644 --- a/apollo-router/src/services/layers/query_analysis.rs +++ b/apollo-router/src/services/layers/query_analysis.rs @@ -2,7 +2,7 @@ use std::collections::HashMap; use std::fmt::Display; use std::fmt::Formatter; use std::hash::Hash; -use std::sync::Arc; +use std::sync::{Arc, Mutex}; use apollo_compiler::ast; use apollo_compiler::validation::Valid; @@ -10,7 +10,8 @@ use apollo_compiler::ExecutableDocument; use http::StatusCode; use lru::LruCache; use router_bridge::planner::UsageReporting; -use tokio::sync::Mutex; +use tokio::task; +use tracing::Instrument; use crate::context::OPERATION_KIND; use crate::context::OPERATION_NAME; @@ -105,28 +106,46 @@ impl QueryAnalysisLayer { .query .clone() .expect("query presence was already checked"); - let entry = self - .cache - .lock() - .await - .get(&QueryAnalysisKey { - query: query.clone(), - operation_name: op_name.clone(), - }) - .cloned(); + + let entry = { + let mut cache = self.cache.lock().unwrap(); + cache + .get(&QueryAnalysisKey { + query: query.clone(), + operation_name: op_name.clone(), + }) + .cloned() + }; let res = match entry { None => { let span = tracing::info_span!("parse_query", "otel.kind" = "INTERNAL"); - match span.in_scope(|| self.parse_document(&query, op_name.as_deref())) { + + let schema = self.schema.clone(); + let conf = self.configuration.clone(); + let q = query.clone(); + let op = op_name.clone(); + + let result = task::spawn_blocking(move || { + Query::parse_document(q.as_str(), op.as_deref(), schema.as_ref(), conf.as_ref()) + }) + .instrument(span) + .await + .unwrap(); + + match result { Err(errors) => { - (*self.cache.lock().await).put( - QueryAnalysisKey { - query, - operation_name: op_name, - }, - Err(errors.clone()), - ); + { + let mut cache = self.cache.lock().unwrap(); + cache.put( + QueryAnalysisKey { + query, + operation_name: op_name, + }, + Err(errors.clone()), + ); + } + let errors = match errors.into_graphql_errors() { Ok(v) => v, Err(errors) => vec![Error::builder() @@ -168,13 +187,16 @@ impl QueryAnalysisLayer { .insert(OPERATION_KIND, operation_kind.unwrap_or_default()) .expect("cannot insert operation kind in the context; this is a bug"); - (*self.cache.lock().await).put( - QueryAnalysisKey { - query, - operation_name: op_name, - }, - Ok((context.clone(), doc.clone())), - ); + { + let mut cache = self.cache.lock().unwrap(); + cache.put( + QueryAnalysisKey { + query, + operation_name: op_name, + }, + Ok((context.clone(), doc.clone())), + ); + } Ok((context, doc)) } From 98908a13296a537c009b7813b6bab3b641c2a405 Mon Sep 17 00:00:00 2001 From: Marc-Andre Giroux Date: Fri, 24 May 2024 10:21:11 -0400 Subject: [PATCH 02/15] changeset --- .changesets/fix_spawn_blocking_parser.md | 6 ++++++ 1 file changed, 6 insertions(+) create mode 100644 .changesets/fix_spawn_blocking_parser.md diff --git a/.changesets/fix_spawn_blocking_parser.md b/.changesets/fix_spawn_blocking_parser.md new file mode 100644 index 0000000000..c0b5cf5b9f --- /dev/null +++ b/.changesets/fix_spawn_blocking_parser.md @@ -0,0 +1,6 @@ +### use spawn_blocking for query parsing & validation ([PR #5235](https://github.com/apollographql/router/pull/5235)) + +This PR runs query parsing and validation in a tokio blocking task to avoid blocking workers during longer +parse and validation times. + +By [@xuorig](https://github.com/xuorig) in https://github.com/apollographql/router/pull/5235 \ No newline at end of file From 8e5e47f9066814cd25b2d106c134ffff7a9df25c Mon Sep 17 00:00:00 2001 From: Marc-Andre Giroux Date: Fri, 24 May 2024 10:25:34 -0400 Subject: [PATCH 03/15] fmt --- apollo-router/src/services/layers/query_analysis.rs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/apollo-router/src/services/layers/query_analysis.rs b/apollo-router/src/services/layers/query_analysis.rs index 660660c93a..1d25696692 100644 --- a/apollo-router/src/services/layers/query_analysis.rs +++ b/apollo-router/src/services/layers/query_analysis.rs @@ -2,7 +2,8 @@ use std::collections::HashMap; use std::fmt::Display; use std::fmt::Formatter; use std::hash::Hash; -use std::sync::{Arc, Mutex}; +use std::sync::Arc; +use std::sync::Mutex; use apollo_compiler::ast; use apollo_compiler::validation::Valid; From 70f1f1b7b13822ea6f5fe9436d76587e9086a9af Mon Sep 17 00:00:00 2001 From: Marc-Andre Giroux Date: Fri, 24 May 2024 10:31:48 -0400 Subject: [PATCH 04/15] dont change mutex yet --- .../src/services/layers/query_analysis.rs | 56 ++++++++----------- 1 file changed, 24 insertions(+), 32 deletions(-) diff --git a/apollo-router/src/services/layers/query_analysis.rs b/apollo-router/src/services/layers/query_analysis.rs index 1d25696692..a3cf87f73d 100644 --- a/apollo-router/src/services/layers/query_analysis.rs +++ b/apollo-router/src/services/layers/query_analysis.rs @@ -3,7 +3,6 @@ use std::fmt::Display; use std::fmt::Formatter; use std::hash::Hash; use std::sync::Arc; -use std::sync::Mutex; use apollo_compiler::ast; use apollo_compiler::validation::Valid; @@ -11,6 +10,7 @@ use apollo_compiler::ExecutableDocument; use http::StatusCode; use lru::LruCache; use router_bridge::planner::UsageReporting; +use tokio::sync::Mutex; use tokio::task; use tracing::Instrument; @@ -107,16 +107,15 @@ impl QueryAnalysisLayer { .query .clone() .expect("query presence was already checked"); - - let entry = { - let mut cache = self.cache.lock().unwrap(); - cache - .get(&QueryAnalysisKey { - query: query.clone(), - operation_name: op_name.clone(), - }) - .cloned() - }; + let entry = self + .cache + .lock() + .await + .get(&QueryAnalysisKey { + query: query.clone(), + operation_name: op_name.clone(), + }) + .cloned(); let res = match entry { None => { @@ -136,17 +135,13 @@ impl QueryAnalysisLayer { match result { Err(errors) => { - { - let mut cache = self.cache.lock().unwrap(); - cache.put( - QueryAnalysisKey { - query, - operation_name: op_name, - }, - Err(errors.clone()), - ); - } - + (*self.cache.lock().await).put( + QueryAnalysisKey { + query, + operation_name: op_name, + }, + Err(errors.clone()), + ); let errors = match errors.into_graphql_errors() { Ok(v) => v, Err(errors) => vec![Error::builder() @@ -188,16 +183,13 @@ impl QueryAnalysisLayer { .insert(OPERATION_KIND, operation_kind.unwrap_or_default()) .expect("cannot insert operation kind in the context; this is a bug"); - { - let mut cache = self.cache.lock().unwrap(); - cache.put( - QueryAnalysisKey { - query, - operation_name: op_name, - }, - Ok((context.clone(), doc.clone())), - ); - } + (*self.cache.lock().await).put( + QueryAnalysisKey { + query, + operation_name: op_name, + }, + Ok((context.clone(), doc.clone())), + ); Ok((context, doc)) } From b4625cc77b0414ae067a473fe908f74f5b80a35f Mon Sep 17 00:00:00 2001 From: Marc-Andre Giroux Date: Tue, 28 May 2024 15:11:54 -0400 Subject: [PATCH 05/15] refactor, spawn_blocking in warm up as well --- .../query_planner/caching_query_planner.rs | 4 +-- .../src/services/layers/query_analysis.rs | 34 +++++++++++-------- 2 files changed, 22 insertions(+), 16 deletions(-) diff --git a/apollo-router/src/query_planner/caching_query_planner.rs b/apollo-router/src/query_planner/caching_query_planner.rs index f6b04aba23..e5e55361fd 100644 --- a/apollo-router/src/query_planner/caching_query_planner.rs +++ b/apollo-router/src/query_planner/caching_query_planner.rs @@ -251,7 +251,7 @@ where } in all_cache_keys { let context = Context::new(); - let doc = match query_analysis.parse_document(&query, operation.as_deref()) { + let doc = match query_analysis.parse_document(&query, operation.as_deref()).await { Ok(doc) => doc, Err(_) => continue, }; @@ -289,7 +289,7 @@ where }) .await; if entry.is_first() { - let doc = match query_analysis.parse_document(&query, operation.as_deref()) { + let doc = match query_analysis.parse_document(&query, operation.as_deref()).await { Ok(doc) => doc, Err(error) => { let e = Arc::new(QueryPlannerError::SpecError(error)); diff --git a/apollo-router/src/services/layers/query_analysis.rs b/apollo-router/src/services/layers/query_analysis.rs index a3cf87f73d..fbb8594056 100644 --- a/apollo-router/src/services/layers/query_analysis.rs +++ b/apollo-router/src/services/layers/query_analysis.rs @@ -65,12 +65,26 @@ impl QueryAnalysisLayer { } } - pub(crate) fn parse_document( + pub(crate) async fn parse_document( &self, query: &str, operation_name: Option<&str>, ) -> Result { - Query::parse_document(query, operation_name, &self.schema, &self.configuration) + let query = query.to_string(); + let operation_name = operation_name.map(|o| o.to_string()); + let schema = self.schema.clone(); + let conf = self.configuration.clone(); + + task::spawn_blocking(move || { + Query::parse_document( + &query, + operation_name.as_deref(), + schema.as_ref(), + conf.as_ref(), + ) + }) + .await + .expect("parse_document task panicked") } pub(crate) async fn supergraph_request( @@ -120,18 +134,10 @@ impl QueryAnalysisLayer { let res = match entry { None => { let span = tracing::info_span!("parse_query", "otel.kind" = "INTERNAL"); - - let schema = self.schema.clone(); - let conf = self.configuration.clone(); - let q = query.clone(); - let op = op_name.clone(); - - let result = task::spawn_blocking(move || { - Query::parse_document(q.as_str(), op.as_deref(), schema.as_ref(), conf.as_ref()) - }) - .instrument(span) - .await - .unwrap(); + let result = self + .parse_document(&query, op_name.as_deref()) + .instrument(span) + .await; match result { Err(errors) => { From df8a6b65c2dc89ff10e0e0dea89cc66d553b189d Mon Sep 17 00:00:00 2001 From: Marc-Andre Giroux Date: Wed, 29 May 2024 11:51:50 -0400 Subject: [PATCH 06/15] lint --- .../src/query_planner/caching_query_planner.rs | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/apollo-router/src/query_planner/caching_query_planner.rs b/apollo-router/src/query_planner/caching_query_planner.rs index e5e55361fd..0da02eeb70 100644 --- a/apollo-router/src/query_planner/caching_query_planner.rs +++ b/apollo-router/src/query_planner/caching_query_planner.rs @@ -251,7 +251,10 @@ where } in all_cache_keys { let context = Context::new(); - let doc = match query_analysis.parse_document(&query, operation.as_deref()).await { + let doc = match query_analysis + .parse_document(&query, operation.as_deref()) + .await + { Ok(doc) => doc, Err(_) => continue, }; @@ -289,7 +292,10 @@ where }) .await; if entry.is_first() { - let doc = match query_analysis.parse_document(&query, operation.as_deref()).await { + let doc = match query_analysis + .parse_document(&query, operation.as_deref()) + .await + { Ok(doc) => doc, Err(error) => { let e = Arc::new(QueryPlannerError::SpecError(error)); From c3493e95616f705bc7f02897ff624274cdc0fded Mon Sep 17 00:00:00 2001 From: Marc-Andre Giroux Date: Tue, 25 Jun 2024 12:08:03 -0400 Subject: [PATCH 07/15] lint --- apollo-router/src/services/layers/query_analysis.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/apollo-router/src/services/layers/query_analysis.rs b/apollo-router/src/services/layers/query_analysis.rs index 8a14bfcf9a..acf26265a3 100644 --- a/apollo-router/src/services/layers/query_analysis.rs +++ b/apollo-router/src/services/layers/query_analysis.rs @@ -143,7 +143,7 @@ impl QueryAnalysisLayer { let res = match entry { None => { - let span = tracing::info_span!(QUERY_PARSING_SPAN_NAME, "otel.kind" = "INTERNAL"); + let span = tracing::info_span!(QUERY_PARSING_SPAN_NAME, "otel.kind" = "INTERNAL"); let result = self .parse_document(&query, op_name.as_deref()) .instrument(span) From 1c6df83fd6b0bfa9bc15395e9b35b124ededf6f8 Mon Sep 17 00:00:00 2001 From: Geoffroy Couprie Date: Tue, 2 Jul 2024 10:34:04 +0200 Subject: [PATCH 08/15] update snapshots --- ...apollo_otel_traces__batch_send_header.snap | 48 +++++++++++++++++++ .../apollo_otel_traces__batch_trace_id.snap | 48 +++++++++++++++++++ 2 files changed, 96 insertions(+) diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap index a573b5890f..c1fe319e7a 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap index 9db10c85be..4e1e59aac6 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host From af60e736e2443d76ce6640822e50dc4b30da1dd6 Mon Sep 17 00:00:00 2001 From: Geoffroy Couprie Date: Tue, 2 Jul 2024 10:37:39 +0200 Subject: [PATCH 09/15] Update .changesets/fix_spawn_blocking_parser.md --- .changesets/fix_spawn_blocking_parser.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.changesets/fix_spawn_blocking_parser.md b/.changesets/fix_spawn_blocking_parser.md index c0b5cf5b9f..703ae3698f 100644 --- a/.changesets/fix_spawn_blocking_parser.md +++ b/.changesets/fix_spawn_blocking_parser.md @@ -1,6 +1,6 @@ ### use spawn_blocking for query parsing & validation ([PR #5235](https://github.com/apollographql/router/pull/5235)) -This PR runs query parsing and validation in a tokio blocking task to avoid blocking workers during longer +Moves query parsing and validation in a tokio blocking task to prevent all executor threads from blocking on it parse and validation times. By [@xuorig](https://github.com/xuorig) in https://github.com/apollographql/router/pull/5235 \ No newline at end of file From 6a994d5b65fc20987bc0e8f6588ad754d3e7f9eb Mon Sep 17 00:00:00 2001 From: Geoffroy Couprie Date: Tue, 2 Jul 2024 10:38:15 +0200 Subject: [PATCH 10/15] Update .changesets/fix_spawn_blocking_parser.md --- .changesets/fix_spawn_blocking_parser.md | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/.changesets/fix_spawn_blocking_parser.md b/.changesets/fix_spawn_blocking_parser.md index 703ae3698f..0fd442df94 100644 --- a/.changesets/fix_spawn_blocking_parser.md +++ b/.changesets/fix_spawn_blocking_parser.md @@ -1,6 +1,5 @@ ### use spawn_blocking for query parsing & validation ([PR #5235](https://github.com/apollographql/router/pull/5235)) -Moves query parsing and validation in a tokio blocking task to prevent all executor threads from blocking on it -parse and validation times. +Moves query parsing and validation in a tokio blocking task to prevent all executor threads from blocking on large queries. By [@xuorig](https://github.com/xuorig) in https://github.com/apollographql/router/pull/5235 \ No newline at end of file From f0fed765af463565015fc3866f231330b65b5553 Mon Sep 17 00:00:00 2001 From: Geoffroy Couprie Date: Tue, 2 Jul 2024 11:19:13 +0200 Subject: [PATCH 11/15] check snapshots again --- ...ollo_otel_traces__batch_send_header-2.snap | 48 +++++++++++++++++++ .../apollo_otel_traces__batch_trace_id-2.snap | 48 +++++++++++++++++++ 2 files changed, 96 insertions(+) diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap index a573b5890f..c1fe319e7a 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap index 9db10c85be..4e1e59aac6 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host From 8836e0eb27e8c6f178f6ccafed0c10c5b93fcf45 Mon Sep 17 00:00:00 2001 From: Gary Pennington Date: Tue, 9 Jul 2024 14:37:58 +0100 Subject: [PATCH 12/15] Changing span processing from sync to async requires special handling As per the extensive commentary here: https://docs.rs/tracing/latest/tracing/span/struct.Span.html#method.or_current Let's see if this fixes things. --- apollo-router/src/services/layers/query_analysis.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/apollo-router/src/services/layers/query_analysis.rs b/apollo-router/src/services/layers/query_analysis.rs index acf26265a3..04ef626753 100644 --- a/apollo-router/src/services/layers/query_analysis.rs +++ b/apollo-router/src/services/layers/query_analysis.rs @@ -146,7 +146,7 @@ impl QueryAnalysisLayer { let span = tracing::info_span!(QUERY_PARSING_SPAN_NAME, "otel.kind" = "INTERNAL"); let result = self .parse_document(&query, op_name.as_deref()) - .instrument(span) + .instrument(span.or_current()) .await; match result { From 0c5d696c23adc1d9ee1f9b673953978a32417938 Mon Sep 17 00:00:00 2001 From: Gary Pennington Date: Tue, 9 Jul 2024 15:23:18 +0100 Subject: [PATCH 13/15] revert snapshot changes They should be the same as in dev. --- ...ollo_otel_traces__batch_send_header-2.snap | 48 ------------------- ...apollo_otel_traces__batch_send_header.snap | 48 ------------------- .../apollo_otel_traces__batch_trace_id-2.snap | 48 ------------------- .../apollo_otel_traces__batch_trace_id.snap | 48 ------------------- 4 files changed, 192 deletions(-) diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap index c1fe319e7a..a573b5890f 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap @@ -228,54 +228,6 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" - - resource: - attributes: - - key: apollo.client.host - value: - stringValue: "[redacted]" - - key: apollo.client.uname - value: - stringValue: "[redacted]" - - key: apollo.graph.ref - value: - stringValue: test - - key: apollo.router.id - value: - stringValue: "[redacted]" - - key: apollo.schema.id - value: - stringValue: "[redacted]" - - key: apollo.user.agent - value: - stringValue: "[redacted]" - droppedAttributesCount: 0 - scopeSpans: - - scope: - name: apollo-router - version: "[version]" - attributes: [] - droppedAttributesCount: 0 - spans: - - traceId: "[trace_id]" - spanId: "[span_id]" - traceState: "" - parentSpanId: "[span_id]" - flags: 0 - name: parse_query - kind: 1 - startTimeUnixNano: "[start_time]" - endTimeUnixNano: "[end_time]" - attributes: [] - droppedAttributesCount: 0 - events: [] - droppedEventsCount: 0 - links: [] - droppedLinksCount: 0 - status: - message: "" - code: 0 - schemaUrl: "" - schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap index c1fe319e7a..a573b5890f 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap @@ -228,54 +228,6 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" - - resource: - attributes: - - key: apollo.client.host - value: - stringValue: "[redacted]" - - key: apollo.client.uname - value: - stringValue: "[redacted]" - - key: apollo.graph.ref - value: - stringValue: test - - key: apollo.router.id - value: - stringValue: "[redacted]" - - key: apollo.schema.id - value: - stringValue: "[redacted]" - - key: apollo.user.agent - value: - stringValue: "[redacted]" - droppedAttributesCount: 0 - scopeSpans: - - scope: - name: apollo-router - version: "[version]" - attributes: [] - droppedAttributesCount: 0 - spans: - - traceId: "[trace_id]" - spanId: "[span_id]" - traceState: "" - parentSpanId: "[span_id]" - flags: 0 - name: parse_query - kind: 1 - startTimeUnixNano: "[start_time]" - endTimeUnixNano: "[end_time]" - attributes: [] - droppedAttributesCount: 0 - events: [] - droppedEventsCount: 0 - links: [] - droppedLinksCount: 0 - status: - message: "" - code: 0 - schemaUrl: "" - schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap index 4e1e59aac6..9db10c85be 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap @@ -228,54 +228,6 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" - - resource: - attributes: - - key: apollo.client.host - value: - stringValue: "[redacted]" - - key: apollo.client.uname - value: - stringValue: "[redacted]" - - key: apollo.graph.ref - value: - stringValue: test - - key: apollo.router.id - value: - stringValue: "[redacted]" - - key: apollo.schema.id - value: - stringValue: "[redacted]" - - key: apollo.user.agent - value: - stringValue: "[redacted]" - droppedAttributesCount: 0 - scopeSpans: - - scope: - name: apollo-router - version: "[version]" - attributes: [] - droppedAttributesCount: 0 - spans: - - traceId: "[trace_id]" - spanId: "[span_id]" - traceState: "" - parentSpanId: "[span_id]" - flags: 0 - name: parse_query - kind: 1 - startTimeUnixNano: "[start_time]" - endTimeUnixNano: "[end_time]" - attributes: [] - droppedAttributesCount: 0 - events: [] - droppedEventsCount: 0 - links: [] - droppedLinksCount: 0 - status: - message: "" - code: 0 - schemaUrl: "" - schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap index 4e1e59aac6..9db10c85be 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap @@ -228,54 +228,6 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" - - resource: - attributes: - - key: apollo.client.host - value: - stringValue: "[redacted]" - - key: apollo.client.uname - value: - stringValue: "[redacted]" - - key: apollo.graph.ref - value: - stringValue: test - - key: apollo.router.id - value: - stringValue: "[redacted]" - - key: apollo.schema.id - value: - stringValue: "[redacted]" - - key: apollo.user.agent - value: - stringValue: "[redacted]" - droppedAttributesCount: 0 - scopeSpans: - - scope: - name: apollo-router - version: "[version]" - attributes: [] - droppedAttributesCount: 0 - spans: - - traceId: "[trace_id]" - spanId: "[span_id]" - traceState: "" - parentSpanId: "[span_id]" - flags: 0 - name: parse_query - kind: 1 - startTimeUnixNano: "[start_time]" - endTimeUnixNano: "[end_time]" - attributes: [] - droppedAttributesCount: 0 - events: [] - droppedEventsCount: 0 - links: [] - droppedLinksCount: 0 - status: - message: "" - code: 0 - schemaUrl: "" - schemaUrl: "" - resource: attributes: - key: apollo.client.host From f08769f606a21f589926034a4daee80b415bf7a7 Mon Sep 17 00:00:00 2001 From: Gary Pennington Date: Tue, 9 Jul 2024 15:35:17 +0100 Subject: [PATCH 14/15] Try to cleanup snapshots Not sure exactly what is happening here, but ... --- ...ollo_otel_traces__batch_send_header-2.snap | 48 +++++++++++++++++++ ...apollo_otel_traces__batch_send_header.snap | 48 +++++++++++++++++++ .../apollo_otel_traces__batch_trace_id-2.snap | 48 +++++++++++++++++++ .../apollo_otel_traces__batch_trace_id.snap | 48 +++++++++++++++++++ 4 files changed, 192 insertions(+) diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap index a573b5890f..c1fe319e7a 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header-2.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap index a573b5890f..c1fe319e7a 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_send_header.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap index 9db10c85be..4e1e59aac6 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id-2.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host diff --git a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap index 9db10c85be..4e1e59aac6 100644 --- a/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap +++ b/apollo-router/tests/snapshots/apollo_otel_traces__batch_trace_id.snap @@ -228,6 +228,54 @@ resourceSpans: code: 0 schemaUrl: "" schemaUrl: "" + - resource: + attributes: + - key: apollo.client.host + value: + stringValue: "[redacted]" + - key: apollo.client.uname + value: + stringValue: "[redacted]" + - key: apollo.graph.ref + value: + stringValue: test + - key: apollo.router.id + value: + stringValue: "[redacted]" + - key: apollo.schema.id + value: + stringValue: "[redacted]" + - key: apollo.user.agent + value: + stringValue: "[redacted]" + droppedAttributesCount: 0 + scopeSpans: + - scope: + name: apollo-router + version: "[version]" + attributes: [] + droppedAttributesCount: 0 + spans: + - traceId: "[trace_id]" + spanId: "[span_id]" + traceState: "" + parentSpanId: "[span_id]" + flags: 0 + name: parse_query + kind: 1 + startTimeUnixNano: "[start_time]" + endTimeUnixNano: "[end_time]" + attributes: [] + droppedAttributesCount: 0 + events: [] + droppedEventsCount: 0 + links: [] + droppedLinksCount: 0 + status: + message: "" + code: 0 + schemaUrl: "" + schemaUrl: "" - resource: attributes: - key: apollo.client.host From 996914c15fb823b03881087f282338b84da9f02d Mon Sep 17 00:00:00 2001 From: Gary Pennington Date: Tue, 9 Jul 2024 16:28:49 +0100 Subject: [PATCH 15/15] Another try at fixing the snapshot inconsistency This might be the solution I've been looking for. Make sure to create the spawn outside of the call to spawn_blocking. --- .../src/services/layers/query_analysis.rs | 27 +++++++++---------- 1 file changed, 13 insertions(+), 14 deletions(-) diff --git a/apollo-router/src/services/layers/query_analysis.rs b/apollo-router/src/services/layers/query_analysis.rs index 04ef626753..71eae898e7 100644 --- a/apollo-router/src/services/layers/query_analysis.rs +++ b/apollo-router/src/services/layers/query_analysis.rs @@ -12,7 +12,6 @@ use lru::LruCache; use router_bridge::planner::UsageReporting; use tokio::sync::Mutex; use tokio::task; -use tracing::Instrument; use crate::apollo_studio_interop::generate_extended_references; use crate::apollo_studio_interop::ExtendedReferenceStats; @@ -85,13 +84,19 @@ impl QueryAnalysisLayer { let schema = self.schema.clone(); let conf = self.configuration.clone(); + // Must be created *outside* of the spawn_blocking or the span is not connected to the + // parent + let span = tracing::info_span!(QUERY_PARSING_SPAN_NAME, "otel.kind" = "INTERNAL"); + task::spawn_blocking(move || { - Query::parse_document( - &query, - operation_name.as_deref(), - schema.as_ref(), - conf.as_ref(), - ) + span.in_scope(|| { + Query::parse_document( + &query, + operation_name.as_deref(), + schema.as_ref(), + conf.as_ref(), + ) + }) }) .await .expect("parse_document task panicked") @@ -143,13 +148,7 @@ impl QueryAnalysisLayer { let res = match entry { None => { - let span = tracing::info_span!(QUERY_PARSING_SPAN_NAME, "otel.kind" = "INTERNAL"); - let result = self - .parse_document(&query, op_name.as_deref()) - .instrument(span.or_current()) - .await; - - match result { + match self.parse_document(&query, op_name.as_deref()).await { Err(errors) => { (*self.cache.lock().await).put( QueryAnalysisKey {