Skip to content

Commit

Permalink
feat: A way to disable slow query logging for some queries (#1297)
Browse files Browse the repository at this point in the history
## What ❔

A  way to disable slow query reporting on a per-query granularity

## Why ❔

Slow queries generate lots of spam and we expect some queries to be
slow.

---------

Signed-off-by: tomg10 <lemures64@gmail.com>
  • Loading branch information
tomg10 committed Feb 29, 2024
1 parent 533f013 commit 13b82a0
Show file tree
Hide file tree
Showing 2 changed files with 21 additions and 7 deletions.
24 changes: 17 additions & 7 deletions core/lib/dal/src/instrument.rs
Original file line number Diff line number Diff line change
Expand Up @@ -103,6 +103,7 @@ struct InstrumentedData<'a> {
location: &'static Location<'static>,
args: QueryArgs<'a>,
report_latency: bool,
slow_query_reporting_enabled: bool,
}

impl<'a> InstrumentedData<'a> {
Expand All @@ -112,6 +113,7 @@ impl<'a> InstrumentedData<'a> {
location,
args: QueryArgs::default(),
report_latency: false,
slow_query_reporting_enabled: true,
}
}

Expand All @@ -125,6 +127,7 @@ impl<'a> InstrumentedData<'a> {
location,
args,
report_latency,
slow_query_reporting_enabled,
} = self;
let started_at = Instant::now();
tokio::pin!(query_future);
Expand All @@ -137,13 +140,15 @@ impl<'a> InstrumentedData<'a> {
Ok(output) => output,
Err(_) => {
let connection_tags = StorageProcessorTags::display(connection_tags);
tracing::warn!(
"Query {name}{args} called at {file}:{line} [{connection_tags}] is executing for more than {slow_query_threshold:?}",
file = location.file(),
line = location.line()
);
REQUEST_METRICS.request_slow[&name].inc();
is_slow = true;
if slow_query_reporting_enabled {
tracing::warn!(
"Query {name}{args} called at {file}:{line} [{connection_tags}] is executing for more than {slow_query_threshold:?}",
file = location.file(),
line = location.line()
);
REQUEST_METRICS.request_slow[&name].inc();
is_slow = true;
}
query_future.await
}
};
Expand Down Expand Up @@ -196,6 +201,11 @@ impl<'a, Q> Instrumented<'a, Q> {
self
}

pub fn expect_slow_query(mut self) -> Self {
self.data.slow_query_reporting_enabled = false;
self
}

/// Adds a traced query argument. The argument will be logged (using `Debug`) if the query executes too slow
/// or finishes with an error.
pub fn with_arg(mut self, name: &'static str, value: &'a ThreadSafeDebug) -> Self {
Expand Down
4 changes: 4 additions & 0 deletions core/lib/dal/src/snapshots_creator_dal.rs
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ impl SnapshotsCreatorDal<'_, '_> {
)
.instrument("get_storage_logs_count")
.report_latency()
.expect_slow_query()
.fetch_one(self.storage)
.await?
.index;
Expand Down Expand Up @@ -60,6 +61,7 @@ impl SnapshotsCreatorDal<'_, '_> {
.instrument("get_storage_logs_row_count")
.with_arg("miniblock_number", &at_miniblock)
.report_latency()
.expect_slow_query()
.fetch_one(self.storage)
.await?;
Ok(row.count.unwrap_or(0) as u64)
Expand Down Expand Up @@ -116,6 +118,7 @@ impl SnapshotsCreatorDal<'_, '_> {
.with_arg("min_hashed_key", &hashed_keys_range.start())
.with_arg("max_hashed_key", &hashed_keys_range.end())
.report_latency()
.expect_slow_query()
.fetch_all(self.storage)
.await?
.iter()
Expand Down Expand Up @@ -151,6 +154,7 @@ impl SnapshotsCreatorDal<'_, '_> {
)
.instrument("get_all_factory_deps")
.report_latency()
.expect_slow_query()
.fetch_all(self.storage)
.await?;

Expand Down

0 comments on commit 13b82a0

Please sign in to comment.