From 8fca76065a3a0c46989a4366875aa9b663703001 Mon Sep 17 00:00:00 2001
From: tyrelr <44035897+tyrelr@users.noreply.github.com>
Date: Mon, 12 Sep 2022 19:22:15 -0600
Subject: [PATCH] Sqlite explain plan log efficiency (#2091)

* capture operation codes by reference

* use Vec instead of HashSet for results

* check logging enabled before cloning result
---
 sqlx-core/src/logger.rs                    | 35 +++++++++++++---------
 sqlx-core/src/sqlite/connection/explain.rs | 19 +++++++-----
 2 files changed, 32 insertions(+), 22 deletions(-)

diff --git a/sqlx-core/src/logger.rs b/sqlx-core/src/logger.rs
index 32583d20..f26bb850 100644
--- a/sqlx-core/src/logger.rs
+++ b/sqlx-core/src/logger.rs
@@ -85,32 +85,41 @@ impl<'q> Drop for QueryLogger<'q> {
 }
 
 #[cfg(feature = "sqlite")]
-pub(crate) struct QueryPlanLogger<'q, O: Debug + Hash + Eq, R: Debug + Hash + Eq, P: Debug> {
+pub(crate) struct QueryPlanLogger<'q, O: Debug + Hash + Eq, R: Debug, P: Debug> {
     sql: &'q str,
     unknown_operations: HashSet<O>,
-    results: HashSet<R>,
-    program: Vec<P>,
+    results: Vec<R>,
+    program: &'q [P],
     settings: LogSettings,
 }
 
 #[cfg(feature = "sqlite")]
-impl<'q, O: Debug + Hash + Eq, R: Debug + Hash + Eq, P: Debug> QueryPlanLogger<'q, O, R, P> {
-    pub(crate) fn new(sql: &'q str, settings: LogSettings) -> Self {
+impl<'q, O: Debug + Hash + Eq, R: Debug, P: Debug> QueryPlanLogger<'q, O, R, P> {
+    pub(crate) fn new(sql: &'q str, program: &'q [P], settings: LogSettings) -> Self {
         Self {
             sql,
             unknown_operations: HashSet::new(),
-            results: HashSet::new(),
-            program: Vec::new(),
+            results: Vec::new(),
+            program,
             settings,
         }
     }
 
-    pub(crate) fn add_result(&mut self, result: R) {
-        self.results.insert(result);
+    pub(crate) fn log_enabled(&self) -> bool {
+        if let Some(_lvl) = self
+            .settings
+            .statements_level
+            .to_level()
+            .filter(|lvl| log::log_enabled!(target: "sqlx::explain", *lvl))
+        {
+            return true;
+        } else {
+            return false;
+        }
     }
 
-    pub(crate) fn add_program(&mut self, program: Vec<P>) {
-        self.program = program;
+    pub(crate) fn add_result(&mut self, result: R) {
+        self.results.push(result);
     }
 
     pub(crate) fn add_unknown_operation(&mut self, operation: O) {
@@ -156,9 +165,7 @@ impl<'q, O: Debug + Hash + Eq, R: Debug + Hash + Eq, P: Debug> QueryPlanLogger<'
 }
 
 #[cfg(feature = "sqlite")]
-impl<'q, O: Debug + Hash + Eq, R: Debug + Hash + Eq, P: Debug> Drop
-    for QueryPlanLogger<'q, O, R, P>
-{
+impl<'q, O: Debug + Hash + Eq, R: Debug, P: Debug> Drop for QueryPlanLogger<'q, O, R, P> {
     fn drop(&mut self) {
         self.finish();
     }
diff --git a/sqlx-core/src/sqlite/connection/explain.rs b/sqlx-core/src/sqlite/connection/explain.rs
index 101ca56a..ace42616 100644
--- a/sqlx-core/src/sqlite/connection/explain.rs
+++ b/sqlx-core/src/sqlite/connection/explain.rs
@@ -328,17 +328,17 @@ pub(super) fn explain(
     conn: &mut ConnectionState,
     query: &str,
 ) -> Result<(Vec<SqliteTypeInfo>, Vec<Option<bool>>), Error> {
-    let mut logger = crate::logger::QueryPlanLogger::new(query, conn.log_settings.clone());
-
     let root_block_cols = root_block_columns(conn)?;
     let program: Vec<(i64, String, i64, i64, i64, Vec<u8>)> =
         execute::iter(conn, &format!("EXPLAIN {}", query), None, false)?
             .filter_map(|res| res.map(|either| either.right()).transpose())
             .map(|row| FromRow::from_row(&row?))
             .collect::<Result<Vec<_>, Error>>()?;
-    logger.add_program(program.clone());
     let program_size = program.len();
 
+    let mut logger =
+        crate::logger::QueryPlanLogger::new(query, &program, conn.log_settings.clone());
+
     let mut states = vec![QueryState {
         visited: vec![false; program_size],
         history: Vec::new(),
@@ -588,7 +588,7 @@ pub(super) fn explain(
                             );
                         }
 
-                        _ => logger.add_unknown_operation(program[state.program_i].clone()),
+                        _ => logger.add_unknown_operation(&program[state.program_i]),
                     }
                 }
 
@@ -753,9 +753,12 @@ pub(super) fn explain(
                             .collect(),
                     );
 
-                    let program_history: Vec<(i64, String, i64, i64, i64, Vec<u8>)> =
-                        state.history.iter().map(|i| program[*i].clone()).collect();
-                    logger.add_result((program_history, state.result.clone()));
+                    if logger.log_enabled() {
+                        let program_history: Vec<&(i64, String, i64, i64, i64, Vec<u8>)> =
+                            state.history.iter().map(|i| &program[*i]).collect();
+                        logger.add_result((program_history, state.result.clone()));
+                    }
+
                     result_states.push(state.clone());
                 }
 
@@ -766,7 +769,7 @@ pub(super) fn explain(
                 _ => {
                     // ignore unsupported operations
                     // if we fail to find an r later, we just give up
-                    logger.add_unknown_operation(program[state.program_i].clone());
+                    logger.add_unknown_operation(&program[state.program_i]);
                 }
             }