Add slow query parse logging

.schema/pgdog.schema.json

@@ -66,6 +66,8 @@
         "log_disconnections": true,
         "log_format": "text",
         "log_level": "info",
+        "log_min_duration_parse": null,
+        "log_query_sample_length": 1000,
         "lsn_check_delay": 9223372036854775807,
         "lsn_check_interval": 5000,
         "lsn_check_timeout": 5000,
@@ -828,6 +830,22 @@
           "type": "string",
           "default": "info"
         },
+        "log_min_duration_parse": {
+          "description": "Minimum parse duration in milliseconds that triggers a warning log with the query text.\nQueries whose parsing takes longer than this value are logged at WARN level.\nSet to `0` or omit to disable.\n\n_Default:_ `None` (disabled)",
+          "type": [
+            "integer",
+            "null"
+          ],
+          "format": "uint64",
+          "minimum": 0
+        },
+        "log_query_sample_length": {
+          "description": "Maximum number of characters of the query text included in log messages.\n\n_Default:_ `1000`",
+          "type": "integer",
+          "format": "uint",
+          "default": 1000,
+          "minimum": 0
+        },
         "lsn_check_delay": {
           "description": "For how long to delay checking for replication delay.\n\nhttps://docs.pgdog.dev/configuration/pgdog.toml/general/#lsn_check_delay",
           "type": "integer",

pgdog-config/src/general.rs

@@ -265,6 +265,19 @@ pub struct General {
     #[serde(default)]
     pub query_log: Option<PathBuf>,
 
+    /// Minimum parse duration in milliseconds that triggers a warning log with the query text.
+    /// Queries whose parsing takes longer than this value are logged at WARN level.
+    /// Set to `0` or omit to disable.
+    ///
+    /// _Default:_ `None` (disabled)
+    pub log_min_duration_parse: Option<u64>,
+
+    /// Maximum number of characters of the query text included in log messages.
+    ///
+    /// _Default:_ `1000`
+    #[serde(default = "General::log_query_sample_length")]
+    pub log_query_sample_length: usize,
+
     /// The port used for the OpenMetrics HTTP endpoint.
     ///
     /// https://docs.pgdog.dev/configuration/pgdog.toml/general/#openmetrics_port
@@ -764,6 +777,8 @@ impl Default for General {
             broadcast_address: Self::broadcast_address(),
             broadcast_port: Self::broadcast_port(),
             query_log: Self::query_log(),
+            log_min_duration_parse: Self::default_log_min_duration_parse(),
+            log_query_sample_length: Self::log_query_sample_length(),
             openmetrics_port: Self::openmetrics_port(),
             openmetrics_namespace: Self::openmetrics_namespace(),
             prepared_statements: Self::prepared_statements(),
@@ -1139,6 +1154,18 @@ impl General {
         Self::env_option_string("PGDOG_QUERY_LOG").map(PathBuf::from)
     }
 
+    fn default_log_min_duration_parse() -> Option<u64> {
+        Self::env_option("PGDOG_LOG_MIN_DURATION_PARSE")
+    }
+
+    pub fn log_min_duration_parse(&self) -> Option<Duration> {
+        self.log_min_duration_parse.map(Duration::from_millis)
+    }
+
+    pub fn log_query_sample_length() -> usize {
+        Self::env_or_default("PGDOG_LOG_QUERY_SAMPLE_LENGTH", 1000)
+    }
+
     pub fn openmetrics_port() -> Option<u16> {
         Self::env_option("PGDOG_OPENMETRICS_PORT")
     }
@@ -1537,6 +1564,8 @@ mod tests {
         env::set_var("PGDOG_MIRROR_EXPOSURE", "0.5");
         env::set_var("PGDOG_DNS_TTL", "60000");
         env::set_var("PGDOG_PUB_SUB_CHANNEL_SIZE", "100");
+        env::set_var("PGDOG_LOG_MIN_DURATION_PARSE", "5");
+        env::set_var("PGDOG_LOG_QUERY_SAMPLE_LENGTH", "200");
 
         assert_eq!(General::broadcast_port(), 7432);
         assert_eq!(General::openmetrics_port(), Some(9090));
@@ -1547,6 +1576,8 @@ mod tests {
         assert_eq!(General::mirror_exposure(), 0.5);
         assert_eq!(General::default_dns_ttl(), Some(60000));
         assert_eq!(General::pub_sub_channel_size(), 100);
+        assert_eq!(General::default_log_min_duration_parse(), Some(5));
+        assert_eq!(General::log_query_sample_length(), 200);
 
         env::remove_var("PGDOG_BROADCAST_PORT");
         env::remove_var("PGDOG_OPENMETRICS_PORT");
@@ -1557,6 +1588,8 @@ mod tests {
         env::remove_var("PGDOG_MIRROR_EXPOSURE");
         env::remove_var("PGDOG_DNS_TTL");
         env::remove_var("PGDOG_PUB_SUB_CHANNEL_SIZE");
+        env::remove_var("PGDOG_LOG_MIN_DURATION_PARSE");
+        env::remove_var("PGDOG_LOG_QUERY_SAMPLE_LENGTH");
 
         assert_eq!(General::broadcast_port(), General::port() + 1);
         assert_eq!(General::openmetrics_port(), None);
@@ -1567,6 +1600,8 @@ mod tests {
         assert_eq!(General::mirror_exposure(), 1.0);
         assert_eq!(General::default_dns_ttl(), None);
         assert_eq!(General::pub_sub_channel_size(), 0);
+        assert_eq!(General::default_log_min_duration_parse(), None);
+        assert_eq!(General::log_query_sample_length(), 1000);
     }
 
     #[test]

pgdog/src/backend/pool/cluster.rs

@@ -76,6 +76,8 @@ pub struct Cluster {
     connection_recovery: ConnectionRecovery,
     client_connection_recovery: ConnectionRecovery,
     query_parser_engine: QueryParserEngine,
+    log_min_duration_parse: Option<Duration>,
+    log_query_sample_length: usize,
     reload_schema_on_ddl: bool,
     load_schema: LoadSchema,
     resharding_parallel_copies: usize,
@@ -97,6 +99,8 @@ pub struct ShardingSchema {
     pub rewrite: Rewrite,
     /// Query parser engine.
     pub query_parser_engine: QueryParserEngine,
+    pub log_min_duration_parse: Option<Duration>,
+    pub log_query_sample_length: usize,
 }
 
 impl ShardingSchema {
@@ -152,6 +156,8 @@ pub struct ClusterConfig<'a> {
     pub pub_sub_channel_size: usize,
     pub query_parser: QueryParserLevel,
     pub query_parser_engine: QueryParserEngine,
+    pub log_min_duration_parse: Option<Duration>,
+    pub log_query_sample_length: usize,
     pub connection_recovery: ConnectionRecovery,
     pub client_connection_recovery: ConnectionRecovery,
     pub lsn_check_interval: Duration,
@@ -209,6 +215,8 @@ impl<'a> ClusterConfig<'a> {
             pub_sub_channel_size: general.pub_sub_channel_size,
             query_parser: general.query_parser,
             query_parser_engine: general.query_parser_engine,
+            log_min_duration_parse: general.log_min_duration_parse(),
+            log_query_sample_length: general.log_query_sample_length,
             connection_recovery: general.connection_recovery,
             client_connection_recovery: general.client_connection_recovery,
             lsn_check_interval: Duration::from_millis(general.lsn_check_interval),
@@ -253,6 +261,8 @@ impl Cluster {
             client_connection_recovery,
             lsn_check_interval,
             query_parser_engine,
+            log_min_duration_parse,
+            log_query_sample_length,
             reload_schema_on_ddl,
             load_schema,
             resharding_parallel_copies,
@@ -307,6 +317,8 @@ impl Cluster {
             connection_recovery,
             client_connection_recovery,
             query_parser_engine,
+            log_min_duration_parse,
+            log_query_sample_length,
             reload_schema_on_ddl,
             load_schema,
             resharding_parallel_copies,
@@ -514,6 +526,8 @@ impl Cluster {
             schemas: self.sharded_schemas.clone(),
             rewrite: self.rewrite.clone(),
             query_parser_engine: self.query_parser_engine,
+            log_min_duration_parse: self.log_min_duration_parse,
+            log_query_sample_length: self.log_query_sample_length,
         }
     }
 

pgdog/src/frontend/router/parser/cache/ast.rs

@@ -7,6 +7,7 @@ use std::{collections::HashSet, ops::Deref};
 
 use parking_lot::Mutex;
 use std::sync::Arc;
+use tracing::warn;
 
 use super::super::{Error, Route, Shard, StatementRewrite, StatementRewriteContext, Table};
 use super::{Cache, Fingerprint, Stats};
@@ -105,6 +106,16 @@ impl Ast {
         let mut stats = Stats::new();
         stats.parse_time += elapsed;
 
+        if let Some(threshold) = schema.log_min_duration_parse {
+            if elapsed >= threshold {
+                warn!(
+                    "[slow_query_parse] parse_time_in_ms={}ms truncated_query=\"{}\"",
+                    elapsed.as_millis(),
+                    query.truncated_query(schema.log_query_sample_length),
+                );
+            }
+        }
+
         Ok(Self {
             cached: true,
             comment_shard: None,

pgdog/src/frontend/router/parser/cache/context.rs

@@ -62,4 +62,14 @@ impl<'a> AstQuery<'a> {
             original_query: query,
         }
     }
+
+    /// Return the first `sample_len` characters of the original query, including any comment.
+    pub fn truncated_query(&self, sample_len: usize) -> &str {
+        let query = self.original_query.query();
+        let end = query
+            .char_indices()
+            .nth(sample_len)
+            .map_or(query.len(), |(i, _)| i);
+        &query[..end]
+    }
 }

pgdog/src/frontend/router/parser/cache/test.rs

@@ -332,6 +332,36 @@ fn test_cache_key_shared_across_different_comments() {
     assert_eq!(matching[0].as_str(), "SELECT 1 FROM cache_key_shared");
 }
 
+#[test]
+fn test_truncated_query_shorter_than_limit() {
+    let buffered = BufferedQuery::Query(Query::new("SELECT 1"));
+    let ast_query = AstQuery::from_query(&buffered);
+    assert_eq!(ast_query.truncated_query(100), "SELECT 1");
+}
+
+#[test]
+fn test_truncated_query_longer_than_limit() {
+    let buffered = BufferedQuery::Query(Query::new("SELECT * FROM users WHERE id = 1"));
+    let ast_query = AstQuery::from_query(&buffered);
+    assert_eq!(ast_query.truncated_query(6), "SELECT");
+}
+
+#[test]
+fn test_truncated_query_includes_leading_comment() {
+    let buffered = BufferedQuery::Query(Query::new("/* shard=0 */ SELECT 1"));
+    let ast_query = AstQuery::from_query(&buffered);
+    assert!(ast_query.truncated_query(100).starts_with("/* shard=0 */"));
+}
+
+#[test]
+fn test_truncated_query_non_ascii_char_boundary() {
+    // '€' is 3 bytes in UTF-8 — truncating at a byte boundary mid-character
+    // must not panic and must return whole characters only
+    let buffered = BufferedQuery::Query(Query::new("SELECT '€'"));
+    let ast_query = AstQuery::from_query(&buffered);
+    assert_eq!(ast_query.truncated_query(9), "SELECT '€");
+}
+
 #[test]
 fn test_normalize() {
     let q = "SELECT * FROM users WHERE id = 1";