From 0fd585364625affe00982c5ee67b84501a982359 Mon Sep 17 00:00:00 2001 From: Folke Behrens Date: Wed, 8 Feb 2023 20:57:45 +0100 Subject: [PATCH 1/2] Don't emit INFO spans for administrative queries This prevents internal queries like `SELECT @@max_allowed_packet` from showing up in user tracing unless tracing level TRACE is allowed. --- src/conn/mod.rs | 6 +++--- src/conn/routines/query.rs | 29 ++++++++++++++++++++--------- src/queryable/mod.rs | 28 ++++++++++++++++++++++++++-- 3 files changed, 49 insertions(+), 14 deletions(-) diff --git a/src/conn/mod.rs b/src/conn/mod.rs index b4ead418..7b996269 100644 --- a/src/conn/mod.rs +++ b/src/conn/mod.rs @@ -887,7 +887,7 @@ impl Conn { /// Do nothing if socket address is already in [`Opts`] or if `prefer_socket` is `false`. async fn read_socket(&mut self) -> Result<()> { if self.inner.opts.prefer_socket() && self.inner.socket.is_none() { - let row_opt = self.query_first("SELECT @@socket").await?; + let row_opt = self.query_internal("SELECT @@socket").await?; self.inner.socket = row_opt.unwrap_or((None,)).0; } Ok(()) @@ -898,7 +898,7 @@ impl Conn { let max_allowed_packet = if let Some(value) = self.opts().max_allowed_packet() { Some(value) } else { - self.query_first("SELECT @@max_allowed_packet").await? + self.query_internal("SELECT @@max_allowed_packet").await? }; if let Some(stream) = self.inner.stream.as_mut() { stream.set_max_allowed_packet(max_allowed_packet.unwrap_or(DEFAULT_MAX_ALLOWED_PACKET)); @@ -911,7 +911,7 @@ impl Conn { let wait_timeout = if let Some(value) = self.opts().wait_timeout() { Some(value) } else { - self.query_first("SELECT @@wait_timeout").await? + self.query_internal("SELECT @@wait_timeout").await? }; self.inner.wait_timeout = Duration::from_secs(wait_timeout.unwrap_or(28800) as u64); Ok(()) diff --git a/src/conn/routines/query.rs b/src/conn/routines/query.rs index 775a2644..a994ea14 100644 --- a/src/conn/routines/query.rs +++ b/src/conn/routines/query.rs @@ -2,7 +2,7 @@ use futures_core::future::BoxFuture; use futures_util::FutureExt; use mysql_common::constants::Command; #[cfg(feature = "tracing")] -use tracing::{field, info_span, Instrument, Level}; +use tracing::{field, info_span, span_enabled, trace_span, Instrument, Level}; use crate::{Conn, TextProtocol}; @@ -12,24 +12,35 @@ use super::Routine; #[derive(Debug, Copy, Clone)] pub struct QueryRoutine<'a> { data: &'a [u8], + #[cfg_attr(not(feature = "tracing"), allow(dead_code))] + internal: bool, } impl<'a> QueryRoutine<'a> { - pub fn new(data: &'a [u8]) -> Self { - Self { data } + pub fn new(data: &'a [u8], internal: bool) -> Self { + Self { data, internal } } } impl Routine<()> for QueryRoutine<'_> { fn call<'a>(&'a mut self, conn: &'a mut Conn) -> BoxFuture<'a, crate::Result<()>> { #[cfg(feature = "tracing")] - let span = info_span!( - "mysql_async::query", - mysql_async.connection.id = conn.id(), - mysql_async.query.sql = field::Empty - ); + let span = if self.internal { + trace_span!( + "mysql_async::query", + mysql_async.connection.id = conn.id(), + mysql_async.query.sql = field::Empty + ) + } else { + info_span!( + "mysql_async::query", + mysql_async.connection.id = conn.id(), + mysql_async.query.sql = field::Empty + ) + }; + #[cfg(feature = "tracing")] - if tracing::span_enabled!(Level::DEBUG) { + if span_enabled!(Level::DEBUG) { // The statement may contain sensitive data. Restrict to DEBUG. span.record( "mysql_async.query.sql", diff --git a/src/queryable/mod.rs b/src/queryable/mod.rs index 52bb4252..e449acf7 100644 --- a/src/queryable/mod.rs +++ b/src/queryable/mod.rs @@ -106,9 +106,33 @@ impl Conn { where Q: AsQuery + 'a, { - self.routine(QueryRoutine::new(query.as_query().as_ref())) + self.routine(QueryRoutine::new(query.as_query().as_ref(), false)) .await } + + /// Used for internal querying of connection settings, + /// bypassing instrumentation meant for user queries. + // This is a merge of `Queryable::query_first` and `Conn::query_iter`. + // TODO: find a cleaner way without duplicating code. + pub(crate) fn query_internal<'a, T, Q>(&'a mut self, query: Q) -> BoxFuture<'a, Option> + where + Q: AsQuery + 'a, + T: FromRow + Send + 'static, + { + async move { + self.routine(QueryRoutine::new(query.as_query().as_ref(), true)) + .await?; + let mut result: QueryResult<'a, 'static, TextProtocol> = QueryResult::new(self); + let output = if result.is_empty() { + None + } else { + result.next().await?.map(crate::from_row) + }; + result.drop_result().await?; + Ok(output) + } + .boxed() + } } /// Methods of this trait are used to execute database queries. @@ -456,7 +480,7 @@ impl Queryable for Conn { Q: AsQuery + 'a, { async move { - self.routine(QueryRoutine::new(query.as_query().as_ref())) + self.routine(QueryRoutine::new(query.as_query().as_ref(), false)) .await?; Ok(QueryResult::new(self)) } From 72dded05d34822e97e41b9e98df0601137916e38 Mon Sep 17 00:00:00 2001 From: Anatoly Ikorsky Date: Mon, 13 Feb 2023 20:12:55 +0300 Subject: [PATCH 2/2] Move QueryRoutine tracing level to compile time --- src/conn/mod.rs | 2 +- src/conn/routines/query.rs | 40 ++++++++++++++++++-------------------- src/lib.rs | 3 +++ src/query.rs | 3 ++- src/queryable/mod.rs | 23 +++++++++------------- src/tracing_utils.rs | 40 ++++++++++++++++++++++++++++++++++++++ 6 files changed, 74 insertions(+), 37 deletions(-) create mode 100644 src/tracing_utils.rs diff --git a/src/conn/mod.rs b/src/conn/mod.rs index 7b996269..04c1e5f7 100644 --- a/src/conn/mod.rs +++ b/src/conn/mod.rs @@ -888,7 +888,7 @@ impl Conn { async fn read_socket(&mut self) -> Result<()> { if self.inner.opts.prefer_socket() && self.inner.socket.is_none() { let row_opt = self.query_internal("SELECT @@socket").await?; - self.inner.socket = row_opt.unwrap_or((None,)).0; + self.inner.socket = row_opt.unwrap_or(None); } Ok(()) } diff --git a/src/conn/routines/query.rs b/src/conn/routines/query.rs index a994ea14..60e5f4bf 100644 --- a/src/conn/routines/query.rs +++ b/src/conn/routines/query.rs @@ -1,43 +1,41 @@ +use std::marker::PhantomData; + use futures_core::future::BoxFuture; use futures_util::FutureExt; use mysql_common::constants::Command; #[cfg(feature = "tracing")] -use tracing::{field, info_span, span_enabled, trace_span, Instrument, Level}; +use tracing::{field, span_enabled, Instrument, Level}; +use crate::tracing_utils::TracingLevel; use crate::{Conn, TextProtocol}; use super::Routine; /// A routine that performs `COM_QUERY`. #[derive(Debug, Copy, Clone)] -pub struct QueryRoutine<'a> { +pub struct QueryRoutine<'a, L: TracingLevel> { data: &'a [u8], - #[cfg_attr(not(feature = "tracing"), allow(dead_code))] - internal: bool, + _phantom: PhantomData, } -impl<'a> QueryRoutine<'a> { - pub fn new(data: &'a [u8], internal: bool) -> Self { - Self { data, internal } +impl<'a, L: TracingLevel> QueryRoutine<'a, L> { + pub fn new(data: &'a [u8]) -> Self { + Self { + data, + _phantom: PhantomData, + } } } -impl Routine<()> for QueryRoutine<'_> { +impl Routine<()> for QueryRoutine<'_, L> { fn call<'a>(&'a mut self, conn: &'a mut Conn) -> BoxFuture<'a, crate::Result<()>> { #[cfg(feature = "tracing")] - let span = if self.internal { - trace_span!( - "mysql_async::query", - mysql_async.connection.id = conn.id(), - mysql_async.query.sql = field::Empty - ) - } else { - info_span!( - "mysql_async::query", - mysql_async.connection.id = conn.id(), - mysql_async.query.sql = field::Empty - ) - }; + let span = create_span!( + L::LEVEL, + "mysql_async::query", + mysql_async.connection.id = conn.id(), + mysql_async.query.sql = field::Empty, + ); #[cfg(feature = "tracing")] if span_enabled!(Level::DEBUG) { diff --git a/src/lib.rs b/src/lib.rs index 2e0a6e09..528c013a 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -424,6 +424,9 @@ use std::sync::Arc; mod buffer_pool; +#[macro_use] +mod tracing_utils; + #[macro_use] mod macros; mod conn; diff --git a/src/query.rs b/src/query.rs index 6637a9d3..976c1724 100644 --- a/src/query.rs +++ b/src/query.rs @@ -14,6 +14,7 @@ use crate::{ connection_like::ToConnectionResult, from_row, prelude::{FromRow, StatementLike, ToConnection}, + tracing_utils::LevelInfo, BinaryProtocol, BoxFuture, Params, QueryResult, ResultSetStream, TextProtocol, }; @@ -220,7 +221,7 @@ impl Query for Q { ToConnectionResult::Immediate(conn) => conn, ToConnectionResult::Mediate(fut) => fut.await?, }; - conn.raw_query(self).await?; + conn.raw_query::<'_, _, LevelInfo>(self).await?; Ok(QueryResult::new(conn)) } .boxed() diff --git a/src/queryable/mod.rs b/src/queryable/mod.rs index e449acf7..79062ec6 100644 --- a/src/queryable/mod.rs +++ b/src/queryable/mod.rs @@ -30,6 +30,7 @@ use crate::{ prelude::{FromRow, StatementLike}, query::AsQuery, queryable::query_result::ResultSetMeta, + tracing_utils::{LevelInfo, LevelTrace, TracingLevel}, BoxFuture, Column, Conn, Params, ResultSetStream, Row, }; @@ -102,11 +103,11 @@ impl Conn { } /// Low level function that performs a text query. - pub(crate) async fn raw_query<'a, Q>(&'a mut self, query: Q) -> Result<()> + pub(crate) async fn raw_query<'a, Q, L: TracingLevel>(&'a mut self, query: Q) -> Result<()> where Q: AsQuery + 'a, { - self.routine(QueryRoutine::new(query.as_query().as_ref(), false)) + self.routine(QueryRoutine::<'_, L>::new(query.as_query().as_ref())) .await } @@ -120,16 +121,11 @@ impl Conn { T: FromRow + Send + 'static, { async move { - self.routine(QueryRoutine::new(query.as_query().as_ref(), true)) - .await?; - let mut result: QueryResult<'a, 'static, TextProtocol> = QueryResult::new(self); - let output = if result.is_empty() { - None - } else { - result.next().await?.map(crate::from_row) - }; - result.drop_result().await?; - Ok(output) + self.raw_query::<'_, _, LevelTrace>(query).await?; + Ok(QueryResult::<'_, '_, TextProtocol>::new(self) + .collect_and_drop::() + .await? + .pop()) } .boxed() } @@ -480,8 +476,7 @@ impl Queryable for Conn { Q: AsQuery + 'a, { async move { - self.routine(QueryRoutine::new(query.as_query().as_ref(), false)) - .await?; + self.raw_query::<'_, _, LevelInfo>(query).await?; Ok(QueryResult::new(self)) } .boxed() diff --git a/src/tracing_utils.rs b/src/tracing_utils.rs new file mode 100644 index 00000000..4321fbb0 --- /dev/null +++ b/src/tracing_utils.rs @@ -0,0 +1,40 @@ +/// Compile-time tracing level. +pub trait TracingLevel: Send + Sync + 'static { + #[cfg(feature = "tracing")] + const LEVEL: tracing::Level; +} + +/// INFO tracing level. +pub struct LevelInfo; + +impl TracingLevel for LevelInfo { + #[cfg(feature = "tracing")] + const LEVEL: tracing::Level = tracing::Level::INFO; +} + +/// TRACE tracing level. +pub struct LevelTrace; + +impl TracingLevel for LevelTrace { + #[cfg(feature = "tracing")] + const LEVEL: tracing::Level = tracing::Level::TRACE; +} + +#[cfg(feature = "tracing")] +macro_rules! create_span { + ($s:expr, $($field:tt)*) => { + if $s == tracing::Level::TRACE { + tracing::trace_span!($($field)*) + } else if $s == tracing::Level::DEBUG { + tracing::debug_span!($($field)*) + } else if $s == tracing::Level::INFO { + tracing::info_span!($($field)*) + } else if $s == tracing::Level::WARN { + tracing::warn_span!($($field)*) + } else if $s == tracing::Level::ERROR { + tracing::error_span!($($field)*) + } else { + unreachable!(); + } + } +}