sqlx
sqlx copied to clipboard
launchbadge
How to pretty print the DB statement on `debug` level?
I'm trying to understand how can I "pretty" format the below traced DB statement sqlx gives me using tracing:
2023-08-01T15:54:42.675396Z DEBUG sqlx::query:117: summary: "SELECT \"user\".* FROM \"user\" …", db.statement: "\n\nSELECT\n \"user\".*\nFROM\n \"user\"\nWHERE\n \"user\".\"id\" = $1\n", rows_affected: 0, rows_returned: 1, elapsed: 2.8366ms
Is there a way to have something like the below instead?
SELECT "user".* FROM "user" WHERE "user"."id" = '1'
I need this when something is broken and I need to debug. I'm using debug level in this case in fact.
I found this https://www.sea-ql.org/SeaORM/docs/install-and-config/debug-log/
It worked fine adding "debug-print" to the dependency.
and then
RUST_LOG=debug cargo run ....
:+1:
( I still need to turn of the sqlx-log but that is a different thing... )
Consume (swallow) and re-export sqlx::query logs in custom format:
(The color-sql is an example feature flag I created to enable SQL syntax highlighting; you don't have to use a feature flag; or, strip it out if you don't want syntax highlighting.)
Cargo.toml
[dependencies]
# sqlx ...
# ...
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.19", features = ["env-filter"] }
syntect = { optional = true, version = "5.2.0" }
[features]
default = ["color-sql"]
color-sql = ["dep:syntect"]
main.rs / lib.rs:
mod sqlx_layer;
use sqlx_layer::SqlxLayer;
#[cfg(feature = "color-sql")]
mod sql_highlighter;
use tracing::{instrument::WithSubscriber, level_filters::LevelFilter};
use tracing_subscriber::{
EnvFilter, Registry,
filter::{FilterFn, Targets, filter_fn},
fmt::{self, time::FormatTime},
prelude::*,
};
fn main() {
// SqlxLayer that consumes and re-emits custom events defined below...
let sqlx_layer = SqlxLayer;
let fmt_subscriber = fmt::layer()
.with_target(true)
.with_level(true)
// remove original sqlx::query events from log output
.with_filter(filter_fn(|metadata| metadata.target() != "sqlx::query"));
Registry::default()
.with(fmt_subscriber)
.with(sqlx_layer)
.init();
}
sqlx_layer.rs:
use std::borrow::BorrowMut;
use tracing::Level;
use tracing::field::{Field, Visit};
use tracing_subscriber::Layer;
use tracing_subscriber::layer::Context;
#[cfg(feature = "color-sql")]
use super::sql_highlighter::SqlHighlighter;
#[cfg(feature = "color-sql")]
use std::sync::LazyLock;
#[cfg(feature = "color-sql")]
static SQL_H: LazyLock<SqlHighlighter> = LazyLock::new(SqlHighlighter::new);
pub struct SqlxLayer;
impl<S> Layer<S> for SqlxLayer
where
S: tracing::Subscriber,
{
fn on_event(&self, event: &tracing::Event<'_>, _ctx: Context<'_, S>) {
if event.metadata().target() != "sqlx::query" {
return;
}
let mut fields = SqlxQueryFields::default();
let mut visitor = SqlxQueryVisitor {
fields: &mut fields,
};
event.record(&mut visitor);
if cfg!(feature = "color-sql") {
fields.sql = SQL_H.highlight_sql(&fields.sql);
};
tracing::event!(
target: "sqlx::formatted_query",
Level::DEBUG, // or whatever level you want queries logged at
sql = %fields.sql,
rows_affected = fields.rows_affected,
rows_returned = fields.rows_returned,
elapsed = fields.elapsed,
elapsed_secs = fields.elapsed_secs,
unknown = fields.unknown,
);
}
}
#[derive(Debug, Default)]
struct SqlxQueryFields {
sql: String,
rows_affected: Option<usize>,
rows_returned: Option<usize>,
elapsed: Option<String>,
elapsed_secs: Option<f64>,
unknown: Option<String>,
}
struct SqlxQueryVisitor<'a> {
fields: &'a mut SqlxQueryFields,
}
impl<'a> Visit for SqlxQueryVisitor<'a> {
fn record_str(&mut self, field: &Field, value: &str) {
let fields = self.fields.borrow_mut();
match field.name() {
"summary" => {}
"db.statement" => fields.sql = value.to_string(),
"rows_affected" => fields.rows_affected = value.parse().ok(),
"rows_returned" => fields.rows_returned = value.parse().ok(),
"elapsed" => fields.elapsed = Some(value.to_string()),
"elapsed_secs" => fields.elapsed_secs = value.parse().ok(),
_ => fields
.unknown
.get_or_insert(String::new())
.push_str(&format!("\n{}={}", field.name(), value)),
}
}
fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
let fields = self.fields.borrow_mut();
let value = format!("{:?}", value);
match field.name() {
"summary" => {}
"db.statement" => fields.sql = value,
"rows_affected" => fields.rows_affected = value.parse().ok(),
"rows_returned" => fields.rows_returned = value.parse().ok(),
"elapsed" => fields.elapsed = Some(value),
"elapsed_secs" => fields.elapsed_secs = value.parse().ok(),
_ => fields
.unknown
.get_or_insert(String::new())
.push_str(&format!("\n{}={:?}", field.name(), value)),
}
}
}
sql_highlighter.rs (optional)
#![cfg(feature = "color-sql")]
use syntect::{
easy::HighlightLines,
highlighting::{Style, Theme, ThemeSet},
parsing::{SyntaxReference, SyntaxSet},
};
pub(crate) struct SqlHighlighter {
syntax: SyntaxReference,
syntax_set: SyntaxSet,
theme: Theme,
}
impl SqlHighlighter {
pub(crate) fn new() -> Self {
let syntax_set = SyntaxSet::load_defaults_newlines();
let syntax = syntax_set
.find_syntax_by_extension("sql")
.expect("SQL not defined")
.clone();
let theme = ThemeSet::load_defaults()
.themes
.get("base16-ocean.dark")
.expect("Theme not found.")
.clone();
Self {
syntax,
syntax_set,
theme,
}
}
pub(crate) fn highlight_sql(&self, sql: &str) -> String {
let mut h = HighlightLines::new(&self.syntax, &self.theme);
sql.lines()
.map(|line| {
let ranges = h.highlight_line(line, &self.syntax_set);
match ranges {
Ok(ranges) => as_terminal_escaped_no_bg(&ranges[..]),
Err(_) => line.to_string(),
}
})
.collect::<Vec<_>>()
.join("\n")
}
}
/// Formats the styled fragments using only foreground 24-bit color terminal escape codes.
fn as_terminal_escaped_no_bg<'a>(ranges: &'a [(Style, &str)]) -> String {
ranges
.iter()
.map(|(style, text)| {
let fg = style.foreground;
format!("\x1b[38;2;{};{};{}m{}", fg.r, fg.g, fg.b, text)
})
.collect::<String>()
+ "\x1b[0m" // Reset colors at the end
}