Geary.Db.Result: Log large elapsed query times as a warning

Help ensure that long-running queries get some visibility during
development.
This commit is contained in:
Michael Gratton 2020-09-05 14:15:28 +10:00 committed by Michael James Gratton
parent 3b6dd30332
commit a1d31847b1

View file

@ -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");
}