Skip to content

Commit b2cd397

Browse files
kamilkisielakamilkisiela
committed
graphql: metrics for validation and parsing phases
1 parent 8ea2995 commit b2cd397

File tree

4 files changed

+92
-4
lines changed

4 files changed

+92
-4
lines changed

‎graph/src/data/query/result.rs

+22-1
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ use serde::ser::*;
99
use serde::Serialize;
1010
use std::convert::TryFrom;
1111
use std::sync::Arc;
12+
use std::time::Duration;
1213

1314
fn serialize_data<S>(data: &Option<Data>, serializer: S) -> Result<S::Ok, S::Error>
1415
where
@@ -45,12 +46,14 @@ pub type Data = Object;
4546
/// A collection of query results that is serialized as a single result.
4647
pub struct QueryResults {
4748
results: Vec<Arc<QueryResult>>,
49+
pub validation_time: Option<Duration>,
4850
}
4951

5052
impl QueryResults {
5153
pub fn empty() -> Self {
5254
QueryResults {
5355
results: Vec::new(),
56+
validation_time: None,
5457
}
5558
}
5659

@@ -72,6 +75,10 @@ impl QueryResults {
7275
.filter_map(|result| result.deployment.as_ref())
7376
.next()
7477
}
78+
79+
pub fn set_validation_time(&mut self, duration: Duration) -> () {
80+
self.validation_time = Some(duration);
81+
}
7582
}
7683

7784
impl Serialize for QueryResults {
@@ -129,6 +136,7 @@ impl From<Data> for QueryResults {
129136
fn from(x: Data) -> Self {
130137
QueryResults {
131138
results: vec![Arc::new(x.into())],
139+
validation_time: None,
132140
}
133141
}
134142
}
@@ -137,20 +145,25 @@ impl From<QueryResult> for QueryResults {
137145
fn from(x: QueryResult) -> Self {
138146
QueryResults {
139147
results: vec![Arc::new(x)],
148+
validation_time: None,
140149
}
141150
}
142151
}
143152

144153
impl From<Arc<QueryResult>> for QueryResults {
145154
fn from(x: Arc<QueryResult>) -> Self {
146-
QueryResults { results: vec![x] }
155+
QueryResults {
156+
results: vec![x],
157+
validation_time: None,
158+
}
147159
}
148160
}
149161

150162
impl From<QueryExecutionError> for QueryResults {
151163
fn from(x: QueryExecutionError) -> Self {
152164
QueryResults {
153165
results: vec![Arc::new(x.into())],
166+
validation_time: None,
154167
}
155168
}
156169
}
@@ -159,6 +172,7 @@ impl From<Vec<QueryExecutionError>> for QueryResults {
159172
fn from(x: Vec<QueryExecutionError>) -> Self {
160173
QueryResults {
161174
results: vec![Arc::new(x.into())],
175+
validation_time: None,
162176
}
163177
}
164178
}
@@ -199,6 +213,8 @@ pub struct QueryResult {
199213
errors: Vec<QueryError>,
200214
#[serde(skip_serializing)]
201215
pub deployment: Option<DeploymentHash>,
216+
#[serde(skip_serializing)]
217+
pub validation_time: Option<Duration>,
202218
}
203219

204220
impl QueryResult {
@@ -207,6 +223,7 @@ impl QueryResult {
207223
data: Some(data),
208224
errors: Vec::new(),
209225
deployment: None,
226+
validation_time: None,
210227
}
211228
}
212229

@@ -219,6 +236,7 @@ impl QueryResult {
219236
data: self.data.clone(),
220237
errors: self.errors.clone(),
221238
deployment: self.deployment.clone(),
239+
validation_time: self.validation_time.clone(),
222240
}
223241
}
224242

@@ -274,6 +292,7 @@ impl From<QueryExecutionError> for QueryResult {
274292
data: None,
275293
errors: vec![e.into()],
276294
deployment: None,
295+
validation_time: None,
277296
}
278297
}
279298
}
@@ -284,6 +303,7 @@ impl From<QueryError> for QueryResult {
284303
data: None,
285304
errors: vec![e],
286305
deployment: None,
306+
validation_time: None,
287307
}
288308
}
289309
}
@@ -294,6 +314,7 @@ impl From<Vec<QueryExecutionError>> for QueryResult {
294314
data: None,
295315
errors: e.into_iter().map(QueryError::from).collect(),
296316
deployment: None,
317+
validation_time: None,
297318
}
298319
}
299320
}

‎graphql/src/execution/query.rs

+8-1
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ use std::collections::{BTreeMap, HashMap, HashSet};
88
use std::hash::{Hash, Hasher};
99
use std::iter::FromIterator;
1010
use std::sync::Arc;
11-
use std::time::Instant;
11+
use std::time::{Duration, Instant};
1212
use std::{collections::hash_map::DefaultHasher, convert::TryFrom};
1313

1414
use graph::data::graphql::{ext::TypeExt, ObjectOrInterface};
@@ -135,6 +135,9 @@ pub struct Query {
135135
pub query_text: Arc<String>,
136136
pub variables_text: Arc<String>,
137137
pub query_id: String,
138+
139+
/// Used only for metrics
140+
pub validation_time: Duration,
138141
}
139142

140143
impl Query {
@@ -150,9 +153,12 @@ impl Query {
150153
max_complexity: Option<u64>,
151154
max_depth: u8,
152155
) -> Result<Arc<Self>, Vec<QueryExecutionError>> {
156+
let validation_phase_start = Instant::now();
153157
let validation_errors =
154158
validate(schema.document(), &query.document, &GRAPHQL_VALIDATION_PLAN);
155159

160+
let validation_time = validation_phase_start.elapsed();
161+
156162
if !validation_errors.is_empty() {
157163
if !ENV_VARS.graphql.silent_graphql_validations {
158164
return Err(validation_errors
@@ -253,6 +259,7 @@ impl Query {
253259
query_text: query.query_text.cheap_clone(),
254260
variables_text: query.variables_text.cheap_clone(),
255261
query_id,
262+
validation_time,
256263
};
257264

258265
Ok(Arc::new(query))

‎graphql/src/runner.rs

+2
Original file line numberDiff line numberDiff line change
@@ -187,6 +187,8 @@ where
187187
let mut max_block = 0;
188188
let mut result: QueryResults = QueryResults::empty();
189189

190+
result.set_validation_time(query.validation_time);
191+
190192
// Note: This will always iterate at least once.
191193
for (bc, (selection_set, error_policy)) in by_block_constraint {
192194
let resolver = StoreResolver::at_block(

‎server/http/src/service.rs

+60-2
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,8 @@ use crate::request::parse_graphql_request;
2020

2121
pub struct GraphQLServiceMetrics {
2222
query_execution_time: Box<HistogramVec>,
23+
query_parsing_time: Box<HistogramVec>,
24+
query_validation_time: Box<HistogramVec>,
2325
}
2426

2527
impl fmt::Debug for GraphQLServiceMetrics {
@@ -38,13 +40,32 @@ impl GraphQLServiceMetrics {
3840
vec![0.1, 0.5, 1.0, 10.0, 100.0],
3941
)
4042
.expect("failed to create `query_execution_time` histogram");
43+
let query_parsing_time = registry
44+
.new_histogram_vec(
45+
"query_parsing_time",
46+
"Parsing time for GraphQL queries",
47+
vec![String::from("deployment"), String::from("status")],
48+
vec![0.1, 0.5, 1.0, 10.0, 100.0],
49+
)
50+
.expect("failed to create `query_parsing_time` histogram");
51+
52+
let query_validation_time = registry
53+
.new_histogram_vec(
54+
"query_validation_time",
55+
"Validation time for GraphQL queries",
56+
vec![String::from("deployment"), String::from("status")],
57+
vec![0.1, 0.5, 1.0, 10.0, 100.0],
58+
)
59+
.expect("failed to create `query_validation_time` histogram");
4160

4261
Self {
4362
query_execution_time,
63+
query_parsing_time,
64+
query_validation_time,
4465
}
4566
}
4667

47-
pub fn observe_query(&self, duration: Duration, results: &QueryResults) {
68+
pub fn observe_query_execution(&self, duration: Duration, results: &QueryResults) {
4869
let id = results
4970
.deployment_hash()
5071
.map(|h| h.as_str())
@@ -64,6 +85,38 @@ impl GraphQLServiceMetrics {
6485
.with_label_values(&[id, status])
6586
.observe(duration.as_secs_f64());
6687
}
88+
89+
pub fn observe_query_parsing(&self, duration: Duration, results: &QueryResults) {
90+
let id = results
91+
.deployment_hash()
92+
.map(|h| h.as_str())
93+
.unwrap_or_else(|| {
94+
if results.not_found() {
95+
"notfound"
96+
} else {
97+
"unknown"
98+
}
99+
});
100+
self.query_parsing_time
101+
.with_label_values(&[id])
102+
.observe(duration.as_secs_f64());
103+
}
104+
105+
pub fn observe_query_validation(&self, duration: Duration, results: &QueryResults) {
106+
let id = results
107+
.deployment_hash()
108+
.map(|h| h.as_str())
109+
.unwrap_or_else(|| {
110+
if results.not_found() {
111+
"notfound"
112+
} else {
113+
"unknown"
114+
}
115+
});
116+
self.query_validation_time
117+
.with_label_values(&[id])
118+
.observe(duration.as_secs_f64());
119+
}
67120
}
68121

69122
pub type GraphQLServiceResult = Result<Response<Body>, GraphQLServerError>;
@@ -189,14 +242,19 @@ where
189242
.map_err(|_| GraphQLServerError::InternalError("Failed to read request body".into()))
190243
.await?;
191244
let query = parse_graphql_request(&body);
245+
let query_parsing_time = start.elapsed();
192246

193247
let result = match query {
194248
Ok(query) => service.graphql_runner.run_query(query, target).await,
195249
Err(GraphQLServerError::QueryError(e)) => QueryResult::from(e).into(),
196250
Err(e) => return Err(e),
197251
};
198252

199-
service_metrics.observe_query(start.elapsed(), &result);
253+
service_metrics.observe_query_parsing(query_parsing_time, &result);
254+
if let Some(query_validation_time) = result.validation_time {
255+
service_metrics.observe_query_validation(query_validation_time, &result);
256+
}
257+
service_metrics.observe_query_execution(start.elapsed(), &result);
200258

201259
Ok(result.as_http_response())
202260
}

0 commit comments

Comments
 (0)