feat: only show SQL in logs for slow queries unless tracing

This commit is contained in:
Greg Heartsfield 2022-12-16 08:17:39 -06:00
parent 4f606615eb
commit e2de162931

View File

@ -594,7 +594,6 @@ fn query_from_sub(sub: &Subscription) -> (String, Vec<Box<dyn ToSql>>) {
.map(|s| format!("SELECT content, created_at FROM ({})", s)) .map(|s| format!("SELECT content, created_at FROM ({})", s))
.collect(); .collect();
let query: String = subqueries_selects.join(" UNION "); let query: String = subqueries_selects.join(" UNION ");
trace!("final query string: {}", query);
(query, params) (query, params)
} }
@ -620,6 +619,8 @@ pub async fn db_query(
trace!("SQL generated in {:?}", start.elapsed()); trace!("SQL generated in {:?}", start.elapsed());
// show pool stats // show pool stats
debug!("DB pool stats: {:?}", pool.state()); debug!("DB pool stats: {:?}", pool.state());
// cutoff for displaying slow queries
let slow_cutoff = Duration::from_millis(200);
let start = Instant::now(); let start = Instant::now();
if let Ok(conn) = pool.get() { if let Ok(conn) = pool.get() {
// execute the query. Don't cache, since queries vary so much. // execute the query. Don't cache, since queries vary so much.
@ -628,11 +629,16 @@ pub async fn db_query(
let mut first_result = true; let mut first_result = true;
while let Some(row) = event_rows.next()? { while let Some(row) = event_rows.next()? {
if first_result { if first_result {
let first_result_elapsed = start.elapsed();
// logging for slow queries
if first_result_elapsed >= slow_cutoff {
info!("final query string (slow): {}", q);
} else {
trace!("final query string: {}", q);
}
debug!( debug!(
"time to first result: {:?} (cid={}, sub={:?})", "time to first result: {:?} (cid={}, sub={:?})",
start.elapsed(), first_result_elapsed, client_id, sub.id
client_id,
sub.id
); );
first_result = false; first_result = false;
} }