Allow configuring the log level of query logging

This commit is contained in:
Jakob Truelsen 2020-08-05 18:04:38 +02:00 committed by Ryan Leckey
parent 12b4250454
commit 9d71a7f372
23 changed files with 204 additions and 43 deletions

View File

@ -2,7 +2,9 @@ use crate::any::AnyConnection;
use crate::connection::ConnectOptions;
use crate::error::Error;
use futures_core::future::BoxFuture;
use log::LevelFilter;
use std::str::FromStr;
use std::time::Duration;
#[cfg(feature = "postgres")]
use crate::postgres::PgConnectOptions;
@ -120,4 +122,54 @@ impl ConnectOptions for AnyConnectOptions {
fn connect(&self) -> BoxFuture<'_, Result<AnyConnection, Error>> {
Box::pin(AnyConnection::establish(self))
}
fn log_statements(&mut self, level: LevelFilter) -> &mut Self {
match &mut self.0 {
#[cfg(feature = "postgres")]
AnyConnectOptionsKind::Postgres(o) => {
o.log_statements(level);
}
#[cfg(feature = "mysql")]
AnyConnectOptionsKind::MySql(o) => {
o.log_statements(level);
}
#[cfg(feature = "sqlite")]
AnyConnectOptionsKind::Sqlite(o) => {
o.log_statements(level);
}
#[cfg(feature = "mssql")]
AnyConnectOptionsKind::Mssql(o) => {
o.log_statements(level);
}
};
self
}
fn log_slow_statements(&mut self, level: LevelFilter, duration: Duration) -> &mut Self {
match &mut self.0 {
#[cfg(feature = "postgres")]
AnyConnectOptionsKind::Postgres(o) => {
o.log_slow_statements(level, duration);
}
#[cfg(feature = "mysql")]
AnyConnectOptionsKind::MySql(o) => {
o.log_slow_statements(level, duration);
}
#[cfg(feature = "sqlite")]
AnyConnectOptionsKind::Sqlite(o) => {
o.log_slow_statements(level, duration);
}
#[cfg(feature = "mssql")]
AnyConnectOptionsKind::Mssql(o) => {
o.log_slow_statements(level, duration);
}
};
self
}
}

View File

@ -3,8 +3,10 @@ use crate::error::Error;
use crate::transaction::Transaction;
use futures_core::future::BoxFuture;
use futures_core::Future;
use log::LevelFilter;
use std::fmt::Debug;
use std::str::FromStr;
use std::time::Duration;
/// Represents a single database connection.
pub trait Connection: Send {
@ -108,6 +110,33 @@ pub trait Connection: Send {
}
}
#[derive(Clone, Debug)]
pub(crate) struct LogSettings {
pub(crate) statements_level: LevelFilter,
pub(crate) slow_statements_level: LevelFilter,
pub(crate) slow_statements_duration: Duration,
}
impl Default for LogSettings {
fn default() -> Self {
LogSettings {
statements_level: LevelFilter::Info,
slow_statements_level: LevelFilter::Warn,
slow_statements_duration: Duration::from_secs(1),
}
}
}
impl LogSettings {
pub(crate) fn log_statements(&mut self, level: LevelFilter) {
self.statements_level = level;
}
pub(crate) fn log_slow_statements(&mut self, level: LevelFilter, duration: Duration) {
self.slow_statements_level = level;
self.slow_statements_duration = duration;
}
}
pub trait ConnectOptions: 'static + Send + Sync + FromStr<Err = Error> + Debug {
type Connection: Connection + ?Sized;
@ -115,4 +144,11 @@ pub trait ConnectOptions: 'static + Send + Sync + FromStr<Err = Error> + Debug {
fn connect(&self) -> BoxFuture<'_, Result<Self::Connection, Error>>
where
Self::Connection: Sized;
/// Log executed statements with the specified `level`
fn log_statements(&mut self, level: LevelFilter) -> &mut Self;
/// Log executed statements with a duration above the specified `duration`
/// at the specified `level`.
fn log_slow_statements(&mut self, level: LevelFilter, duration: Duration) -> &mut Self;
}

View File

@ -1,20 +1,20 @@
use log::Level;
use std::time::{Duration, Instant};
const SLOW_QUERY_THRESHOLD: Duration = Duration::from_secs(1);
use crate::connection::LogSettings;
use std::time::Instant;
pub(crate) struct QueryLogger<'q> {
sql: &'q str,
rows: usize,
start: Instant,
settings: LogSettings,
}
impl<'q> QueryLogger<'q> {
pub(crate) fn new(sql: &'q str) -> Self {
pub(crate) fn new(sql: &'q str, settings: LogSettings) -> Self {
Self {
sql,
rows: 0,
start: Instant::now(),
settings,
}
}
@ -25,42 +25,44 @@ impl<'q> QueryLogger<'q> {
pub(crate) fn finish(&self) {
let elapsed = self.start.elapsed();
let lvl = if elapsed >= SLOW_QUERY_THRESHOLD {
Level::Warn
let lvl = if elapsed >= self.settings.slow_statements_duration {
self.settings.slow_statements_level
} else {
Level::Info
self.settings.statements_level
};
if lvl <= log::STATIC_MAX_LEVEL && lvl <= log::max_level() {
let mut summary = parse_query_summary(&self.sql);
if let Some(lvl) = lvl.to_level() {
if lvl <= log::STATIC_MAX_LEVEL && lvl <= log::max_level() {
let mut summary = parse_query_summary(&self.sql);
let sql = if summary != self.sql {
summary.push_str("");
format!(
"\n\n{}\n",
sqlformat::format(
&self.sql,
&sqlformat::QueryParams::None,
sqlformat::FormatOptions::default()
let sql = if summary != self.sql {
summary.push_str("");
format!(
"\n\n{}\n",
sqlformat::format(
&self.sql,
&sqlformat::QueryParams::None,
sqlformat::FormatOptions::default()
)
)
)
} else {
String::new()
};
} else {
String::new()
};
let rows = self.rows;
let rows = self.rows;
log::logger().log(
&log::Record::builder()
.args(format_args!(
"{}; rows: {}, elapsed: {:.3?}{}",
summary, rows, elapsed, sql
))
.level(lvl)
.module_path_static(Some("sqlx::query"))
.target("sqlx::query")
.build(),
);
log::logger().log(
&log::Record::builder()
.args(format_args!(
"{}; rows: {}, elapsed: {:.3?}{}",
summary, rows, elapsed, sql
))
.level(lvl)
.module_path_static(Some("sqlx::query"))
.target("sqlx::query")
.build(),
);
}
}
}
}

View File

@ -82,6 +82,7 @@ impl MssqlConnection {
Ok(Self {
stream,
cache_statement: StatementCache::new(1024),
log_settings: options.log_settings.clone(),
})
}
}

View File

@ -78,7 +78,7 @@ impl<'c> Executor<'c> for &'c mut MssqlConnection {
{
let sql = query.sql();
let arguments = query.take_arguments();
let mut logger = QueryLogger::new(sql);
let mut logger = QueryLogger::new(sql, self.log_settings.clone());
Box::pin(try_stream! {
self.run(sql, arguments).await?;

View File

@ -1,5 +1,5 @@
use crate::common::StatementCache;
use crate::connection::Connection;
use crate::connection::{Connection, LogSettings};
use crate::error::Error;
use crate::executor::Executor;
use crate::mssql::connection::stream::MssqlStream;
@ -20,6 +20,7 @@ mod stream;
pub struct MssqlConnection {
pub(crate) stream: MssqlStream,
pub(crate) cache_statement: StatementCache<Arc<MssqlStatementMetadata>>,
log_settings: LogSettings,
}
impl Debug for MssqlConnection {

View File

@ -2,6 +2,8 @@ use crate::connection::ConnectOptions;
use crate::error::Error;
use crate::mssql::{MssqlConnectOptions, MssqlConnection};
use futures_core::future::BoxFuture;
use log::LevelFilter;
use std::time::Duration;
impl ConnectOptions for MssqlConnectOptions {
type Connection = MssqlConnection;
@ -12,4 +14,14 @@ impl ConnectOptions for MssqlConnectOptions {
{
Box::pin(MssqlConnection::establish(self))
}
fn log_statements(&mut self, level: LevelFilter) -> &mut Self {
self.log_settings.log_statements(level);
self
}
fn log_slow_statements(&mut self, level: LevelFilter, duration: Duration) -> &mut Self {
self.log_settings.log_slow_statements(level, duration);
self
}
}

View File

@ -1,3 +1,5 @@
use crate::connection::LogSettings;
mod connect;
mod parse;
@ -8,6 +10,7 @@ pub struct MssqlConnectOptions {
pub(crate) username: String,
pub(crate) database: String,
pub(crate) password: Option<String>,
pub(crate) log_settings: LogSettings,
}
impl Default for MssqlConnectOptions {
@ -24,6 +27,7 @@ impl MssqlConnectOptions {
database: String::from("master"),
username: String::from("sa"),
password: None,
log_settings: Default::default(),
}
}

View File

@ -129,6 +129,7 @@ impl MySqlConnection {
stream,
transaction_depth: 0,
cache_statement: StatementCache::new(options.statement_cache_capacity),
log_settings: options.log_settings.clone(),
})
}
}

View File

@ -89,7 +89,7 @@ impl MySqlConnection {
arguments: Option<MySqlArguments>,
persistent: bool,
) -> Result<impl Stream<Item = Result<Either<MySqlDone, MySqlRow>, Error>> + 'e, Error> {
let mut logger = QueryLogger::new(sql);
let mut logger = QueryLogger::new(sql, self.log_settings.clone());
self.stream.wait_until_ready().await?;
self.stream.busy = Busy::Result;

View File

@ -1,5 +1,5 @@
use crate::common::StatementCache;
use crate::connection::Connection;
use crate::connection::{Connection, LogSettings};
use crate::error::Error;
use crate::mysql::protocol::statement::StmtClose;
use crate::mysql::protocol::text::{Ping, Quit};
@ -32,6 +32,8 @@ pub struct MySqlConnection {
// cache by query string to the statement id and metadata
cache_statement: StatementCache<(u32, MySqlStatementMetadata)>,
log_settings: LogSettings,
}
impl Debug for MySqlConnection {

View File

@ -3,6 +3,8 @@ use crate::error::Error;
use crate::executor::Executor;
use crate::mysql::{MySqlConnectOptions, MySqlConnection};
use futures_core::future::BoxFuture;
use log::LevelFilter;
use std::time::Duration;
impl ConnectOptions for MySqlConnectOptions {
type Connection = MySqlConnection;
@ -53,4 +55,14 @@ impl ConnectOptions for MySqlConnectOptions {
Ok(conn)
})
}
fn log_statements(&mut self, level: LevelFilter) -> &mut Self {
self.log_settings.log_statements(level);
self
}
fn log_slow_statements(&mut self, level: LevelFilter, duration: Duration) -> &mut Self {
self.log_settings.log_slow_statements(level, duration);
self
}
}

View File

@ -4,6 +4,7 @@ mod connect;
mod parse;
mod ssl_mode;
use crate::connection::LogSettings;
pub use ssl_mode::MySqlSslMode;
/// Options and flags which can be used to configure a MySQL connection.
@ -65,6 +66,7 @@ pub struct MySqlConnectOptions {
pub(crate) statement_cache_capacity: usize,
pub(crate) charset: String,
pub(crate) collation: Option<String>,
pub(crate) log_settings: LogSettings,
}
impl Default for MySqlConnectOptions {
@ -88,6 +90,7 @@ impl MySqlConnectOptions {
ssl_mode: MySqlSslMode::Preferred,
ssl_ca: None,
statement_cache_capacity: 100,
log_settings: Default::default(),
}
}

View File

@ -142,6 +142,7 @@ impl PgConnection {
cache_statement: StatementCache::new(options.statement_cache_capacity),
cache_type_oid: HashMap::new(),
cache_type_info: HashMap::new(),
log_settings: options.log_settings.clone(),
})
}
}

View File

@ -199,7 +199,7 @@ impl PgConnection {
persistent: bool,
metadata_opt: Option<Arc<PgStatementMetadata>>,
) -> Result<impl Stream<Item = Result<Either<PgDone, PgRow>, Error>> + 'e, Error> {
let mut logger = QueryLogger::new(query);
let mut logger = QueryLogger::new(query, self.log_settings.clone());
// before we continue, wait until we are "ready" to accept more queries
self.wait_until_ready().await?;

View File

@ -6,7 +6,7 @@ use futures_core::future::BoxFuture;
use futures_util::{FutureExt, TryFutureExt};
use crate::common::StatementCache;
use crate::connection::Connection;
use crate::connection::{Connection, LogSettings};
use crate::error::Error;
use crate::executor::Executor;
use crate::ext::ustr::UStr;
@ -60,6 +60,8 @@ pub struct PgConnection {
// current transaction status
transaction_status: TransactionStatus,
pub(crate) transaction_depth: usize,
log_settings: LogSettings,
}
impl PgConnection {

View File

@ -2,6 +2,8 @@ use crate::connection::ConnectOptions;
use crate::error::Error;
use crate::postgres::{PgConnectOptions, PgConnection};
use futures_core::future::BoxFuture;
use log::LevelFilter;
use std::time::Duration;
impl ConnectOptions for PgConnectOptions {
type Connection = PgConnection;
@ -12,4 +14,14 @@ impl ConnectOptions for PgConnectOptions {
{
Box::pin(PgConnection::establish(self))
}
fn log_statements(&mut self, level: LevelFilter) -> &mut Self {
self.log_settings.log_statements(level);
self
}
fn log_slow_statements(&mut self, level: LevelFilter, duration: Duration) -> &mut Self {
self.log_settings.log_slow_statements(level, duration);
self
}
}

View File

@ -4,7 +4,7 @@ use std::path::{Path, PathBuf};
mod connect;
mod parse;
mod ssl_mode;
use crate::connection::LogSettings;
pub use ssl_mode::PgSslMode;
/// Options and flags which can be used to configure a PostgreSQL connection.
@ -85,6 +85,7 @@ pub struct PgConnectOptions {
pub(crate) ssl_root_cert: Option<PathBuf>,
pub(crate) statement_cache_capacity: usize,
pub(crate) application_name: Option<String>,
pub(crate) log_settings: LogSettings,
}
impl Default for PgConnectOptions {
@ -136,6 +137,7 @@ impl PgConnectOptions {
.unwrap_or_default(),
statement_cache_capacity: 100,
application_name: var("PGAPPNAME").ok(),
log_settings: Default::default(),
}
}

View File

@ -114,5 +114,6 @@ pub(crate) async fn establish(options: &SqliteConnectOptions) -> Result<SqliteCo
statements: StatementCache::new(options.statement_cache_capacity),
statement: None,
transaction_depth: 0,
log_settings: options.log_settings.clone(),
})
}

View File

@ -72,7 +72,7 @@ impl<'c> Executor<'c> for &'c mut SqliteConnection {
E: Execute<'q, Self::Database>,
{
let sql = query.sql();
let mut logger = QueryLogger::new(sql);
let mut logger = QueryLogger::new(sql, self.log_settings.clone());
let arguments = query.take_arguments();
let persistent = query.persistent() && arguments.is_some();

View File

@ -1,5 +1,5 @@
use crate::common::StatementCache;
use crate::connection::Connection;
use crate::connection::{Connection, LogSettings};
use crate::error::Error;
use crate::sqlite::statement::{StatementWorker, VirtualStatement};
use crate::sqlite::{Sqlite, SqliteConnectOptions};
@ -32,6 +32,8 @@ pub struct SqliteConnection {
// most recent non-persistent statement
pub(crate) statement: Option<VirtualStatement>,
log_settings: LogSettings,
}
impl SqliteConnection {

View File

@ -4,6 +4,8 @@ use crate::executor::Executor;
use crate::sqlite::connection::establish::establish;
use crate::sqlite::{SqliteConnectOptions, SqliteConnection};
use futures_core::future::BoxFuture;
use log::LevelFilter;
use std::time::Duration;
impl ConnectOptions for SqliteConnectOptions {
type Connection = SqliteConnection;
@ -27,4 +29,14 @@ impl ConnectOptions for SqliteConnectOptions {
Ok(conn)
})
}
fn log_statements(&mut self, level: LevelFilter) -> &mut Self {
self.log_settings.log_statements(level);
self
}
fn log_slow_statements(&mut self, level: LevelFilter, duration: Duration) -> &mut Self {
self.log_settings.log_slow_statements(level, duration);
self
}
}

View File

@ -4,6 +4,7 @@ mod connect;
mod journal_mode;
mod parse;
use crate::connection::LogSettings;
pub use journal_mode::SqliteJournalMode;
use std::{borrow::Cow, time::Duration};
@ -51,6 +52,7 @@ pub struct SqliteConnectOptions {
pub(crate) shared_cache: bool,
pub(crate) statement_cache_capacity: usize,
pub(crate) busy_timeout: Duration,
pub(crate) log_settings: LogSettings,
}
impl Default for SqliteConnectOptions {
@ -71,6 +73,7 @@ impl SqliteConnectOptions {
statement_cache_capacity: 100,
journal_mode: SqliteJournalMode::Wal,
busy_timeout: Duration::from_secs(5),
log_settings: Default::default(),
}
}