async_graphql_logger/
lib.rs

1use async_graphql::{
2    extensions::{
3        Extension, ExtensionContext, ExtensionFactory, NextExecute, NextParseQuery, NextValidation,
4    },
5    parser::types::{ExecutableDocument, OperationType, Selection},
6    Response, ServerError, ServerResult, ValidationResult, Variables,
7};
8use chrono::{DateTime, Utc};
9use rand::Rng;
10use std::sync::Arc;
11use tokio::sync::Mutex;
12
13pub struct Logger;
14
15impl ExtensionFactory for Logger {
16    fn create(&self) -> Arc<dyn Extension> {
17        Arc::new(LoggerExtension {})
18    }
19}
20
21struct LoggerExtension {}
22
23#[derive(Debug, Default)]
24pub struct QueryInfo {
25    inner: Arc<Mutex<QueryInfoInner>>,
26}
27impl QueryInfo {
28    pub fn new() -> QueryInfo {
29        let mut rng = rand::thread_rng();
30        QueryInfo {
31            inner: Arc::new(Mutex::new(QueryInfoInner {
32                id: rng.gen_range(100_000_000..=999_999_999),
33                start_time: Utc::now(),
34                is_schema: false,
35            })),
36        }
37    }
38}
39
40#[derive(Debug, Default)]
41pub struct QueryInfoInner {
42    id: u64,
43    start_time: DateTime<Utc>,
44    is_schema: bool,
45}
46
47#[async_trait::async_trait]
48impl Extension for LoggerExtension {
49    async fn validation(
50        &self,
51        ctx: &ExtensionContext<'_>,
52        next: NextValidation<'_>,
53    ) -> Result<ValidationResult, Vec<ServerError>> {
54        let res = next.run(ctx).await;
55        match res {
56            Ok(_) => res,
57            Err(ref errors) => match ctx.data_opt::<QueryInfo>() {
58                Some(qinfo) => {
59                    let qinfo = qinfo.inner.lock().await;
60                    for e in errors {
61                        log::info!(
62                            target: "gql_logger",
63                            "[QueryID: {}] Validation is failed with reason: {}",
64                            qinfo.id,
65                            e.message
66                        )
67                    }
68                    res
69                }
70                None => res,
71            },
72        }
73    }
74
75    async fn parse_query(
76        &self,
77        ctx: &ExtensionContext<'_>,
78        query: &str,
79        variables: &Variables,
80        next: NextParseQuery<'_>,
81    ) -> ServerResult<ExecutableDocument> {
82        let document = next.run(ctx, query, variables).await?;
83        if let Some(qinfo) = ctx.data_opt::<QueryInfo>() {
84            let is_schema = document
85            .operations
86            .iter()
87            .filter(|(_, operation)| operation.node.ty == OperationType::Query)
88            .any(|(_, operation)| operation.node.selection_set.node.items.iter().any(
89                    |selection| matches!(&selection.node, Selection::Field(field) if field.node.name.node == "__schema")));
90            let mut qinfo = qinfo.inner.lock().await;
91            qinfo.is_schema = is_schema;
92            if is_schema {
93                return Ok(document);
94            }
95            log::info!(target: "gql_logger", "[QueryID: {}] {}", qinfo.id, ctx.stringify_execute_doc(&document, variables));
96        }
97        Ok(document)
98    }
99
100    async fn execute(
101        &self,
102        ctx: &ExtensionContext<'_>,
103        operation_name: Option<&str>,
104        next: NextExecute<'_>,
105    ) -> Response {
106        let resp = next.run(ctx, operation_name).await;
107        if let Some(qinfo) = ctx.data_opt::<QueryInfo>() {
108            let qinfo = qinfo.inner.lock().await;
109            if qinfo.is_schema {
110                return resp;
111            }
112            let query_id = qinfo.id;
113
114            if resp.is_err() {
115                for err in &resp.errors {
116                    log::info!(
117                        target: "gql_logger",
118                        "[QueryID: {query_id}] [Error] {}", err.message,
119                    );
120                }
121            }
122            let query_start_time = qinfo.start_time;
123            let duration = Utc::now() - query_start_time;
124            log::debug!(target: "gql_logger",
125                        "[QueryID: {query_id}] Response: {}", resp.data);
126            log::info!(
127                target: "gql_logger",
128                "[QueryID: {query_id}] Duration: {}ms",
129                duration.num_milliseconds()
130            );
131        }
132
133        resp
134    }
135}
async_graphql_logger/lib.rs

async_graphql_logger/
lib.rs
