[geary/mjog/db-result-timing: 2/3] Geary.Db.Result: Log large elapsed query times as a warning

[Michael Gratton <mjog src gnome org>]

commit d4fd4c7081e21a35e92b570275aeadde665696c0
Author: Michael Gratton <mike vee net>
Date:   Sat Sep 5 14:15:28 2020 +1000

    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 64c787562..3bc47bc41 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;
+            if (threshold > 0 && elapsed > threshold) {
+                warning(
+                    "\n\nDB QUERY STEP \"%s\"\nelapsed=%lf (>50%)\n\n",
+                    statement.sql,
+                    timer.elapsed()
+                );
+            } else if (elapsed > 1.0) {
+                debug(
+                    "\n\nDB QUERY STEP \"%s\"\nelapsed=%lf (>1s)\n\n",
+                    statement.sql,
+                    timer.elapsed()
+                );
+            }
 
             log_result(finished ? "NO ROW" : "ROW");
         }