[geary/mjog/db-result-timing: 5/5] Geary.Db: Update SQL logging

[Michael Gratton <mjog src gnome org>]

commit fe4a4d5b03f687c08f663c127e0819c5b2f9deea
Author: Michael Gratton <mike vee net>
Date:   Wed Sep 9 18:48:43 2020 +1000

    Geary.Db: Update SQL logging
    
    Now that a single code path is responsible for executing all SQL, get
    that also logging the SQL if enabled and clean up the log formatting.
    
    Add new `enable_result_logging` static property to control result
    logging separately from SQL logging, so we can get SQL logged without
    having to see email. Clean up result formatting, and keep track of the
    current result row number and log that as context.

 src/engine/db/db-context.vala             | 17 +++++++++++++----
 src/engine/db/db-database-connection.vala | 10 ++++------
 src/engine/db/db-result.vala              | 27 +++++++++++++++------------
 3 files changed, 32 insertions(+), 22 deletions(-)
---
diff --git a/src/engine/db/db-context.vala b/src/engine/db/db-context.vala
index 2ba8b305d..7b8b9d654 100644
--- a/src/engine/db/db-context.vala
+++ b/src/engine/db/db-context.vala
@@ -16,16 +16,25 @@
 public abstract class Geary.Db.Context : BaseObject, Logging.Source {
 
 
+    /** The GLib logging domain used by this class. */
+    public const string LOGGING_DOMAIN = Logging.DOMAIN + ".Db";
+
+
     /**
-     * Determines if SQL queries and results will be logged.
+     * Determines if SQL queries will be logged.
      *
-     * This will cause extremely verbose logging, so enable with care.
+     * This will cause verbose logging, so enable with care.
      */
     public static bool enable_sql_logging = false;
 
 
-    /** The GLib logging domain used by this class. */
-    public const string LOGGING_DOMAIN = Logging.DOMAIN + ".Db";
+    /**
+     * Determines if SQL results will be logged.
+     *
+     * This will cause extremely verbose logging, so enable with extra care.
+     */
+    public static bool enable_result_logging = false;
+
 
     /** {@inheritDoc} */
     public string logging_domain {
diff --git a/src/engine/db/db-database-connection.vala b/src/engine/db/db-database-connection.vala
index 54d361604..8fb138622 100644
--- a/src/engine/db/db-database-connection.vala
+++ b/src/engine/db/db-database-connection.vala
@@ -123,8 +123,10 @@ public class Geary.Db.DatabaseConnection : Context, Connection {
 
     /** {@inheritDoc} */
     public Statement prepare(string sql) throws DatabaseError {
-        var prepared = new Statement(this, sql);
-        return prepared;
+        if (Db.Context.enable_sql_logging) {
+            debug(sql);
+        }
+        return new Statement(this, sql);
     }
 
     /** {@inheritDoc} */
@@ -136,10 +138,6 @@ public class Geary.Db.DatabaseConnection : Context, Connection {
     /** {@inheritDoc} */
     public void exec(string sql, GLib.Cancellable? cancellable = null)
         throws GLib.Error {
-        if (Db.Context.enable_sql_logging) {
-            debug("exec:\n\t%s", sql);
-        }
-
         check_cancelled("Connection.exec", cancellable);
         var timer = new GLib.Timer();
         throw_on_error("Connection.exec_file", this.db.exec(sql), sql);
diff --git a/src/engine/db/db-result.vala b/src/engine/db/db-result.vala
index 8c40c4759..14dc71a96 100644
--- a/src/engine/db/db-result.vala
+++ b/src/engine/db/db-result.vala
@@ -8,8 +8,12 @@ public class Geary.Db.Result : Geary.Db.Context {
     public bool finished { get; private set; default = false; }
 
 
+    /** The statement this result was generated from. */
     public Statement statement { get; private set; }
 
+    /** The current row represented by this result. */
+    public uint64 row { get; private set; default = 0; }
+
     /** {@inheritDoc} */
     public override Logging.Source? logging_parent {
         get { return this.statement; }
@@ -39,7 +43,8 @@ public class Geary.Db.Result : Geary.Db.Context {
     public bool next(Cancellable? cancellable = null) throws Error {
         check_cancelled("Result.next", cancellable);
 
-        if (!finished) {
+        if (!this.finished) {
+            this.row++;
             var timer = new GLib.Timer();
             this.finished = throw_on_error(
                 "Result.next", statement.stmt.step(), statement.sql
@@ -298,7 +303,12 @@ public class Geary.Db.Result : Geary.Db.Context {
 
     /** {@inheritDoc} */
     public override Logging.State to_logging_state() {
-        return new Logging.State(this, this.finished ? "finished" : "not finished");
+        return new Logging.State(
+            this,
+            "%llu, %s",
+            this.row,
+            this.finished ? "finished" : "!finished"
+        );
     }
 
     internal override Result? get_result() {
@@ -306,16 +316,9 @@ public class Geary.Db.Result : Geary.Db.Context {
     }
 
     [PrintfFormat]
-    private void log_result(string fmt, ...) {
-        if (Db.Context.enable_sql_logging) {
-            Statement? stmt = get_statement();
-            if (stmt != null) {
-                debug("%s\n\t<%s>",
-                      fmt.vprintf(va_list()),
-                      (stmt != null) ? "%.100s".printf(stmt.sql) : "no sql");
-            } else {
-                debug(fmt.vprintf(va_list()));
-            }
+    private inline void log_result(string fmt, ...) {
+        if (Db.Context.enable_result_logging) {
+            debug(fmt.vprintf(va_list()));
         }
     }