Adds some new metrics. These are unstable at the moment and will be d…

…ocumented at the point of stability.

apollo-router/src/context/mod.rs

@@ -70,6 +70,13 @@ impl Context {
 }
 
 impl Context {
+    pub(crate) fn operation_name(&self) -> Option<String> {
+        // This method should be removed once we have a proper way to get the operation name.
+        self.entries
+            .get(OPERATION_NAME)
+            .map(|v| v.value().as_str().unwrap().to_string())
+    }
+
     /// Returns true if the context contains a value for the specified key.
     pub fn contains_key<K>(&self, key: K) -> bool
     where

apollo-router/src/plugins/authentication/mod.rs

@@ -469,6 +469,15 @@ fn authenticate(
             monotonic_counter.apollo_authentication_failure_count = 1u64,
             kind = %AUTHENTICATION_KIND
         );
+        tracing::info!(
+            monotonic_counter
+                .apollo
+                .router
+                .operations
+                .authentication
+                .jwt = 1,
+            authentication.jwt.failed = true
+        );
         tracing::info!(message = %error, "jwt authentication failure");
         let response = router::Response::error_builder()
             .error(
@@ -618,6 +627,7 @@ fn authenticate(
             monotonic_counter.apollo_authentication_success_count = 1u64,
             kind = %AUTHENTICATION_KIND
         );
+        tracing::info!(monotonic_counter.apollo.router.operations.jwt = 1);
         return Ok(ControlFlow::Continue(request));
     }
 

apollo-router/src/plugins/subscription.rs

@@ -447,6 +447,10 @@ impl Service<router::Request> for CallbackService {
                                 };
                                 // Keep the subscription to the client opened
                                 payload.subscribed = Some(true);
+                                tracing::info!(
+                                        monotonic_counter.apollo.router.operations.subscriptions.events = 1u64,
+                                        subscriptions.mode="callback"
+                                    );
                                 handle.send_sync(payload)?;
 
                                 Ok(router::Response {
@@ -545,6 +549,11 @@ impl Service<router::Request> for CallbackService {
                                 if let Some(errors) = errors {
                                     let mut handle =
                                         notify.subscribe(id.clone()).await?.into_sink();
+                                    tracing::info!(
+                                        monotonic_counter.apollo.router.operations.subscriptions.events = 1u64,
+                                        subscriptions.mode="callback",
+                                        subscriptions.complete=true
+                                    );
                                     handle.send_sync(
                                         graphql::Response::builder().errors(errors).build(),
                                     )?;

apollo-router/src/plugins/telemetry/mod.rs

@@ -77,8 +77,10 @@ use crate::plugins::telemetry::apollo::ForwardHeaders;
 use crate::plugins::telemetry::apollo_exporter::proto::reports::trace::node::Id::ResponseName;
 use crate::plugins::telemetry::apollo_exporter::proto::reports::StatsContext;
 use crate::plugins::telemetry::config::AttributeValue;
+use crate::plugins::telemetry::config::Metrics;
 use crate::plugins::telemetry::config::MetricsCommon;
 use crate::plugins::telemetry::config::Trace;
+use crate::plugins::telemetry::config::Tracing;
 use crate::plugins::telemetry::formatters::filter_metric_events;
 use crate::plugins::telemetry::formatters::FilteringFormatter;
 use crate::plugins::telemetry::metrics::aggregation::AggregateMeterProvider;
@@ -95,6 +97,7 @@ use crate::plugins::telemetry::metrics::MetricsExporterHandle;
 use crate::plugins::telemetry::tracing::apollo_telemetry::decode_ftv1_trace;
 use crate::plugins::telemetry::tracing::apollo_telemetry::APOLLO_PRIVATE_OPERATION_SIGNATURE;
 use crate::plugins::telemetry::tracing::TracingConfigurator;
+use crate::plugins::telemetry::utils::TracingUtils;
 use crate::query_planner::OperationKind;
 use crate::register_plugin;
 use crate::router_factory::Endpoint;
@@ -121,6 +124,8 @@ pub(crate) mod metrics;
 mod otlp;
 pub(crate) mod reload;
 pub(crate) mod tracing;
+pub(crate) mod utils;
+
 // Tracing consts
 pub(crate) const SUPERGRAPH_SPAN_NAME: &str = "supergraph";
 pub(crate) const SUBGRAPH_SPAN_NAME: &str = "subgraph";
@@ -292,6 +297,10 @@ impl Plugin for Telemetry {
             .map_future(move |fut| {
                 let start = Instant::now();
                 let config = config_later.clone();
+
+                Self::plugin_metrics(&config);
+
+
                 async move {
                     let span = Span::current();
                     let response: Result<router::Response, BoxError> = fut.await;
@@ -812,6 +821,10 @@ impl Telemetry {
                 if !parts.status.is_success() {
                     metric_attrs.push(KeyValue::new("error", parts.status.to_string()));
                 }
+                ::tracing::info!(
+                    monotonic_counter.apollo.router.operations = 1u64,
+                    http.response.status_code = parts.status.as_u16(),
+                );
                 let response = http::Response::from_parts(
                     parts,
                     once(ready(first_response.unwrap_or_default()))
@@ -824,6 +837,10 @@ impl Telemetry {
             Err(err) => {
                 metric_attrs.push(KeyValue::new("status", "500"));
 
+                ::tracing::info!(
+                    monotonic_counter.apollo.router.operations = 1u64,
+                    http.response.status_code = 500,
+                );
                 Err(err)
             }
         };
@@ -1454,6 +1471,57 @@ impl Telemetry {
         }
         root
     }
+
+    fn plugin_metrics(config: &Arc<Conf>) {
+        let metrics_prom_used = matches!(
+            config.metrics,
+            Some(Metrics {
+                prometheus: Some(_),
+                ..
+            })
+        );
+        let metrics_otlp_used = matches!(config.metrics, Some(Metrics { otlp: Some(_), .. }));
+        let tracing_otlp_used = matches!(config.tracing, Some(Tracing { otlp: Some(_), .. }));
+        let tracing_datadog_used = matches!(
+            config.tracing,
+            Some(Tracing {
+                datadog: Some(_),
+                ..
+            })
+        );
+        let tracing_jaeger_used = matches!(
+            config.tracing,
+            Some(Tracing {
+                jaeger: Some(_),
+                ..
+            })
+        );
+        let tracing_zipkin_used = matches!(
+            config.tracing,
+            Some(Tracing {
+                zipkin: Some(_),
+                ..
+            })
+        );
+
+        if metrics_prom_used
+            || metrics_otlp_used
+            || tracing_jaeger_used
+            || tracing_otlp_used
+            || tracing_zipkin_used
+            || tracing_datadog_used
+        {
+            ::tracing::info!(
+                monotonic_counter.apollo.router.operations.telemetry = 1u64,
+                telemetry.metrics.otlp = metrics_otlp_used.or_empty(),
+                telemetry.metrics.prometheus = metrics_prom_used.or_empty(),
+                telemetry.tracing.otlp = tracing_otlp_used.or_empty(),
+                telemetry.tracing.datadog = tracing_datadog_used.or_empty(),
+                telemetry.tracing.jaeger = tracing_jaeger_used.or_empty(),
+                telemetry.tracing.zipkin = tracing_zipkin_used.or_empty(),
+            );
+        }
+    }
 }
 
 fn filter_headers(headers: &HeaderMap, forward_rules: &ForwardHeaders) -> String {

apollo-router/src/protocols/websocket.rs

@@ -447,6 +447,15 @@ where
     fn start_send(self: Pin<&mut Self>, item: graphql::Request) -> Result<(), Self::Error> {
         let mut this = self.project();
 
+        tracing::info!(
+            monotonic_counter
+                .apollo
+                .router
+                .operations
+                .subscriptions
+                .events = 1u64,
+            subscriptions.mode = "passthrough"
+        );
         Pin::new(&mut this.stream)
             .start_send(this.protocol.subscribe(this.id.to_string(), item))
             .map_err(|_err| {
@@ -474,6 +483,16 @@ where
         self: Pin<&mut Self>,
         cx: &mut std::task::Context<'_>,
     ) -> Poll<Result<(), Self::Error>> {
+        tracing::info!(
+            monotonic_counter
+                .apollo
+                .router
+                .operations
+                .subscriptions
+                .events = 1u64,
+            subscriptions.mode = "passthrough",
+            subscriptions.complete = true
+        );
         let mut this = self.project();
         if !*this.completed {
             match Pin::new(

apollo-router/src/query_planner/execution.rs

@@ -75,6 +75,9 @@ impl QueryPlan {
                 sender,
             )
             .await;
+        if !deferred_fetches.is_empty() {
+            tracing::info!(monotonic_counter.apollo.router.operations.defer = 1);
+        }
 
         Response::builder().data(value).errors(errors).build()
     }

apollo-router/src/query_planner/fetch.rs

@@ -290,6 +290,7 @@ impl FetchNode {
             self.response_at_path(parameters.schema, current_dir, paths, response);
         if let Some(id) = &self.id {
             if let Some(sender) = parameters.deferred_fetches.get(id.as_str()) {
+                tracing::info!(monotonic_counter.apollo.router.operations.defer.fetch = 1);
                 if let Err(e) = sender.clone().send((value.clone(), errors.clone())) {
                     tracing::error!("error sending fetch result at path {} and id {:?} for deferred response building: {}", current_dir, self.id, e);
                 }

apollo-router/src/services/layers/persisted_queries/mod.rs

@@ -12,6 +12,7 @@ use tower::BoxError;
 
 use crate::configuration::PersistedQueriesSafelist;
 use crate::graphql::Error as GraphQLError;
+use crate::plugins::telemetry::utils::TracingUtils;
 use crate::services::SupergraphRequest;
 use crate::services::SupergraphResponse;
 use crate::Configuration;
@@ -169,12 +170,17 @@ impl PersistedQueryLayer {
                 let mut body = request.supergraph_request.body_mut();
                 body.query = Some(persisted_query_body);
                 body.extensions.remove("persistedQuery");
+                tracing::info!(monotonic_counter.apollo.router.operations.persisted_queries = 1u64);
                 Ok(request)
             } else if self.apq_enabled {
                 // if APQ is also enabled, pass the request along to the APQ plugin
                 // where it will do its own lookup
                 Ok(request)
             } else {
+                tracing::info!(
+                    monotonic_counter.apollo.router.operations.persisted_queries = 1u64,
+                    persisted_quieries.not_found = true
+                );
                 // if APQ is not enabled, return an error indicating the query was not found
                 Err(supergraph_err_operation_not_found(
                     request,
@@ -203,25 +209,33 @@ impl PersistedQueryLayer {
 
             let mut is_persisted = None;
 
-            if self.log_unknown
-                && !is_operation_persisted(
-                    &mut is_persisted,
-                    manifest_poller.clone(),
-                    operation_body,
-                )
-            {
+            let known = is_operation_persisted(&mut is_persisted, manifest_poller, operation_body);
+            let logged = self.log_unknown && !known;
+            if logged {
                 tracing::warn!(message = "unknown operation", operation_body);
             }
 
             if self.safelist_config.enabled {
                 if self.safelist_config.require_id {
+                    tracing::info!(
+                        monotonic_counter.apollo.router.operations.persisted_queries = 1u64,
+                        persisted_queries.safelist.rejected.missing_id = true,
+                        persisted_queries.logged = logged.or_empty()
+                    );
                     Err(supergraph_err_pq_id_required(request))
-                } else if is_operation_persisted(&mut is_persisted, manifest_poller, operation_body)
-                {
+                } else if known {
+                    tracing::info!(
+                        monotonic_counter.apollo.router.operations.persisted_queries = 1u64,
+                    );
                     // if the freeform GraphQL body we received was found in the manifest,
                     // allow the request to continue execution
                     Ok(request)
                 } else {
+                    tracing::info!(
+                        monotonic_counter.apollo.router.operations.persisted_queries = 1u64,
+                        persisted_queries.safelist.rejected.unknown = true,
+                        persisted_queries.logged = logged.or_empty()
+                    );
                     Err(supergraph_err_operation_not_in_safelist(request))
                 }
             } else {

apollo-router/src/services/subgraph_service.rs

@@ -293,11 +293,16 @@ impl tower::Service<SubgraphRequest> for SubgraphService {
                             request.subscription_stream.clone().ok_or_else(|| {
                                 FetchError::SubrequestWsError {
                                     service: service_name.clone(),
-                                    reason: "cannot get the websocket stream".to_string(),
+                                    reason: "cannot get the callback stream".to_string(),
                                 }
                             })?;
                         stream_tx.send(handle.into_stream()).await?;
-
+                        tracing::info!(
+                            monotonic_counter.apollo.router.operations.subscriptions = 1u64,
+                            subscriptions.mode = %"callback",
+                            subscriptions.deduplicated = !created,
+                            subgraph.service.name = service_name,
+                        );
                         if !created {
                             tracing::info!(
                                 monotonic_counter.apollo_router_deduplicated_subscriptions_total = 1u64,
@@ -431,11 +436,6 @@ async fn call_websocket(
         subscription_stream,
         ..
     } = request;
-    let operation_name = subgraph_request
-        .body()
-        .operation_name
-        .clone()
-        .unwrap_or_default();
     let mut subscription_stream_tx =
         subscription_stream.ok_or_else(|| FetchError::SubrequestWsError {
             service: service_name.clone(),
@@ -445,6 +445,13 @@ async fn call_websocket(
     let (handle, created) = notify
         .create_or_subscribe(subscription_hash.clone(), false)
         .await?;
+    let operation_name = context.operation_name().unwrap_or_default();
+    tracing::info!(
+        monotonic_counter.apollo.router.operations.subscriptions = 1u64,
+        subscriptions.mode = %"passthrough",
+        subscriptions.deduplicated = !created,
+        subgraph.service.name = service_name,
+    );
     if !created {
         subscription_stream_tx.send(handle.into_stream()).await?;
         tracing::info!(

apollo-router/src/services/supergraph_service.rs

@@ -1,5 +1,6 @@
 //! Implements the router phase of the request lifecycle.
 
+use std::ops::Deref;
 use std::sync::atomic::Ordering;
 use std::sync::Arc;
 use std::task::Poll;

apollo-router/tests/snapshots/tracing_tests__traced_basic_composition.snap

@@ -200,6 +200,14 @@ expression: get_spans()
                   [
                     "apollo_private.operation_signature",
                     "# -\n{topProducts{name reviews{author{id name}id product{name}}upc}}"
+                  ],
+                  [
+                    "monotonic_counter.apollo.router.operations",
+                    1
+                  ],
+                  [
+                    "http.response.status_code",
+                    200
                   ]
                 ],
                 "metadata": {

apollo-router/tests/snapshots/tracing_tests__traced_basic_request.snap

@@ -200,6 +200,14 @@ expression: get_spans()
                   [
                     "apollo_private.operation_signature",
                     "# -\n{topProducts{name name}}"
+                  ],
+                  [
+                    "monotonic_counter.apollo.router.operations",
+                    1
+                  ],
+                  [
+                    "http.response.status_code",
+                    200
                   ]
                 ],
                 "metadata": {

apollo-router/tests/snapshots/tracing_tests__variables.snap

@@ -188,6 +188,14 @@ expression: get_spans()
                   [
                     "apollo_private.operation_signature",
                     "# ExampleQuery\nquery ExampleQuery($reviewsForAuthorAuthorId:ID!,$topProductsFirst:Int){topProducts(first:$topProductsFirst){name reviewsForAuthor(authorID:$reviewsForAuthorAuthorId){author{id name}body}}}"
+                  ],
+                  [
+                    "monotonic_counter.apollo.router.operations",
+                    1
+                  ],
+                  [
+                    "http.response.status_code",
+                    400
                   ]
                 ],
                 "metadata": {