From a1d31847b115e8ac81520226ff121fabc1f2e2ef Mon Sep 17 00:00:00 2001 From: Michael Gratton Date: Sat, 5 Sep 2020 14:15:28 +1000 Subject: [PATCH 002/124] Geary.Db.Result: Log large elapsed query times as a warning Help ensure that long-running queries get some visibility during development. --- src/engine/db/db-result.vala | 19 ++++++++++++++++--- 1 file changed, 16 insertions(+), 3 deletions(-) diff --git a/src/engine/db/db-result.vala b/src/engine/db/db-result.vala index 64c78756..300d3afa 100644 --- a/src/engine/db/db-result.vala +++ b/src/engine/db/db-result.vala @@ -38,10 +38,23 @@ public class Geary.Db.Result : Geary.Db.Context { check_cancelled("Result.next", cancellable); if (!finished) { - Timer timer = new Timer(); + var timer = new GLib.Timer(); finished = throw_on_error("Result.next", statement.stmt.step(), statement.sql) != Sqlite.ROW; - if (timer.elapsed() > 1.0) - debug("\n\nDB QUERY STEP \"%s\"\nelapsed=%lf\n\n", statement.sql, timer.elapsed()); + var elapsed = timer.elapsed(); + var threshold = (get_connection().busy_timeout * 1000.0) / 2.0; + if (threshold > 0 && elapsed > threshold) { + warning( + "Step for \"%s\" took elapsed time: %lfs (>50%)", + statement.sql, + elapsed + ); + } else if (elapsed > 1.0) { + debug( + "Step for \"%s\" took elapsed time: %lfs (>1s)", + statement.sql, + elapsed + ); + } log_result(finished ? "NO ROW" : "ROW"); } -- 2.29.2