graphql: Log cached status of queries

Author: leoyvens

graphql/src/execution/execution.rs

@@ -7,6 +7,7 @@ use stable_hash::prelude::*;
 use stable_hash::utils::stable_hash;
 use std::collections::{BTreeMap, HashMap, HashSet};
 use std::iter;
+use std::sync::atomic::AtomicBool;
 use std::time::Instant;
 
 use graph::prelude::*;
@@ -128,6 +129,9 @@ where
 
     /// Max value for `first`.
     pub max_first: u32,
+
+    /// Set to `true` if the response was cached. Used for logging.
+    pub cached: AtomicBool,
 }
 
 // Helpers to look for types and fields on both the introspection and regular schemas.
@@ -164,6 +168,7 @@ where
             query: self.query.as_introspection_query(),
             deadline: self.deadline,
             max_first: std::u32::MAX,
+            cached: AtomicBool::new(false),
         }
     }
 }
@@ -190,6 +195,7 @@ pub fn execute_root_selection_set(
 
         // Peek because we want even hot entries to invalidate after the expiry period.
         if let Some(response) = cache.peek(key.as_ref().unwrap()) {
+            ctx.cached.store(true, std::sync::atomic::Ordering::SeqCst);
             return Ok(response.clone());
         }
     }

graphql/src/query/mod.rs

@@ -1,7 +1,7 @@
 use graph::prelude::{info, o, Logger, QueryExecutionError};
 use graphql_parser::query as q;
 use std::collections::BTreeMap;
-use std::sync::Arc;
+use std::sync::{atomic::AtomicBool, Arc};
 use std::time::Instant;
 use uuid::Uuid;
 
@@ -54,6 +54,7 @@ where
         query: query.clone(),
         deadline: options.deadline,
         max_first: options.max_first,
+        cached: AtomicBool::new(false),
     };
 
     if !query.is_query() {
@@ -79,6 +80,7 @@ where
             "query" => &query.query_text,
             "variables" => &query.variables_text,
             "query_time_ms" => start.elapsed().as_millis(),
+            "cached" => ctx.cached.load(std::sync::atomic::Ordering::SeqCst),
         );
     }
     result

graphql/src/subscription/mod.rs

@@ -2,7 +2,7 @@ use graphql_parser::{query as q, schema as s};
 use std::collections::HashMap;
 use std::iter;
 use std::result::Result;
-use std::sync::Arc;
+use std::sync::{atomic::AtomicBool, Arc};
 use std::time::{Duration, Instant};
 
 use graph::prelude::*;
@@ -82,6 +82,7 @@ where
         query: query.clone(),
         deadline: None,
         max_first: options.max_first,
+        cached: AtomicBool::new(false),
     };
 
     if !query.is_subscription() {
@@ -197,6 +198,7 @@ async fn execute_subscription_event(
         query,
         deadline: timeout.map(|t| Instant::now() + t),
         max_first,
+        cached: AtomicBool::new(false),
     };
 
     // We have established that this exists earlier in the subscription execution