sui_graphql_rpc/extensions/
logger.rs

1// Copyright (c) Mysten Labs, Inc.
2// SPDX-License-Identifier: Apache-2.0
3
4use crate::{error::code, metrics::Metrics};
5use async_graphql::{
6    extensions::{
7        Extension, ExtensionContext, ExtensionFactory, NextExecute, NextParseQuery, NextResolve,
8        NextValidation, ResolveInfo,
9    },
10    parser::types::{ExecutableDocument, OperationType, Selection},
11    PathSegment, Response, ServerError, ServerResult, ValidationResult, Variables,
12};
13use async_graphql_value::ConstValue;
14use std::{fmt::Write, net::SocketAddr, sync::Arc};
15use tracing::{debug, error, info, warn};
16use uuid::Uuid;
17
18#[derive(Clone, Debug)]
19pub struct LoggerConfig {
20    pub log_request_query: bool,
21    pub log_response: bool,
22    pub log_complexity: bool,
23}
24
25impl Default for LoggerConfig {
26    fn default() -> Self {
27        Self {
28            log_request_query: false,
29            log_response: true,
30            log_complexity: true,
31        }
32    }
33}
34
35#[derive(Clone, Debug, Default)]
36pub struct Logger {
37    config: LoggerConfig,
38}
39
40impl ExtensionFactory for Logger {
41    fn create(&self) -> Arc<dyn Extension> {
42        Arc::new(LoggerExtension {
43            config: self.config.clone(),
44        })
45    }
46}
47
48struct LoggerExtension {
49    config: LoggerConfig,
50}
51
52#[async_trait::async_trait]
53impl Extension for LoggerExtension {
54    // This hook is used to get the top level node name for recording in the metrics which top
55    // level nodes are being called.
56    async fn resolve(
57        &self,
58        ctx: &ExtensionContext<'_>,
59        info: ResolveInfo<'_>,
60        next: NextResolve<'_>,
61    ) -> ServerResult<Option<ConstValue>> {
62        if info.path_node.parent.is_none() {
63            ctx.data_unchecked::<Metrics>()
64                .request_metrics
65                .num_queries_top_level
66                .with_label_values(&[info.name])
67                .inc();
68        }
69        next.run(ctx, info).await
70    }
71
72    async fn parse_query(
73        &self,
74        ctx: &ExtensionContext<'_>,
75        query: &str,
76        variables: &Variables,
77        next: NextParseQuery<'_>,
78    ) -> ServerResult<ExecutableDocument> {
79        let document = next.run(ctx, query, variables).await?;
80        let is_schema = document
81            .operations
82            .iter()
83            .filter(|(_, operation)| operation.node.ty == OperationType::Query)
84            .any(|(_, operation)| operation.node.selection_set.node.items.iter().any(|selection| matches!(&selection.node, Selection::Field(field) if field.node.name.node == "__schema")));
85        let query_id: &Uuid = ctx.data_unchecked();
86        let session_id: &SocketAddr = ctx.data_unchecked();
87        if !is_schema && self.config.log_request_query {
88            info!(
89                %query_id,
90                %session_id,
91                "[Query] {}",
92                ctx.stringify_execute_doc(&document, variables)
93            );
94        }
95        Ok(document)
96    }
97
98    async fn validation(
99        &self,
100        ctx: &ExtensionContext<'_>,
101        next: NextValidation<'_>,
102    ) -> Result<ValidationResult, Vec<ServerError>> {
103        let res = next.run(ctx).await?;
104        let query_id: &Uuid = ctx.data_unchecked();
105        let session_id: &SocketAddr = ctx.data_unchecked();
106        if self.config.log_complexity {
107            info!(
108                %query_id,
109                %session_id,
110                complexity = res.complexity,
111                depth = res.depth,
112                "[Validation]",
113            );
114        }
115        Ok(res)
116    }
117
118    async fn execute(
119        &self,
120        ctx: &ExtensionContext<'_>,
121        operation_name: Option<&str>,
122        next: NextExecute<'_>,
123    ) -> Response {
124        let resp = next.run(ctx, operation_name).await;
125        let query_id: &Uuid = ctx.data_unchecked();
126        let session_id: &SocketAddr = ctx.data_unchecked();
127        if resp.is_err() {
128            for err in &resp.errors {
129                let error_code = &err.extensions.as_ref().and_then(|x| x.get("code"));
130                if !err.path.is_empty() {
131                    let mut path = String::new();
132                    for (idx, s) in err.path.iter().enumerate() {
133                        if idx > 0 {
134                            path.push('.');
135                        }
136                        match s {
137                            PathSegment::Index(idx) => {
138                                let _ = write!(&mut path, "{}", idx);
139                            }
140                            PathSegment::Field(name) => {
141                                let _ = write!(&mut path, "{}", name);
142                            }
143                        }
144                    }
145
146                    if let Some(async_graphql_value::ConstValue::String(error_code)) = error_code {
147                        if error_code.as_str() == code::INTERNAL_SERVER_ERROR {
148                            error!(
149                                %query_id,
150                                %session_id,
151                                error_code,
152                                "[Response] path={} message={}",
153                                path,
154                                err.message,
155                            );
156                        } else {
157                            info!(
158                                %query_id,
159                                %session_id,
160                                error_code,
161                                "[Response] path={} message={}",
162                                path,
163                                err.message,
164                            );
165                        }
166                    } else {
167                        warn!(
168                            %query_id,
169                            %session_id,
170                            error_code = code::UNKNOWN,
171                            "[Response] path={} message={}",
172                            path,
173                            err.message,
174                        );
175                    }
176                } else {
177                    let error_code = if let Some(error_code) = error_code {
178                        error_code.to_string()
179                    } else {
180                        code::UNKNOWN.to_string()
181                    };
182                    info!(
183                        %query_id,
184                        %session_id,
185                        error_code,
186                        "[Response] message={}", err.message
187                    )
188                }
189            }
190        } else if self.config.log_response {
191            match operation_name {
192                Some("IntrospectionQuery") => {
193                    debug!(
194                        %query_id,
195                        %session_id,
196                        "[Schema] {}", resp.data
197                    );
198                }
199                _ => info!(
200                        %query_id,
201                        %session_id,
202                        "[Response] {}", resp.data
203                ),
204            }
205        }
206        resp
207    }
208}
sui_graphql_rpc/extensions/logger.rs

sui_graphql_rpc/extensions/
logger.rs
