From 0f60c285df50586058f9368c29f7b288c8076b76 Mon Sep 17 00:00:00 2001
From: Michael Gratton <mike@vee.net>
Date: Wed, 9 Sep 2020 18:48:43 +1000
Subject: [PATCH 007/124] Geary.Db: Update SQL logging

Ensure all code paths that execute SQL are logging it 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 | 14 +++++++-----
 src/engine/db/db-result.vala              | 27 +++++++++++++----------
 3 files changed, 37 insertions(+), 21 deletions(-)

diff --git a/src/engine/db/db-context.vala b/src/engine/db/db-context.vala
index 2ba8b305..7b8b9d65 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 54d36160..29d52fd1 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,11 +138,10 @@ public class Geary.Db.DatabaseConnection : Context, Connection {
     /** {@inheritDoc} */
     public void exec(string sql, GLib.Cancellable? cancellable = null)
         throws GLib.Error {
+        check_cancelled("Connection.exec", cancellable);
         if (Db.Context.enable_sql_logging) {
-            debug("exec:\n\t%s", sql);
+            debug(sql);
         }
-
-        check_cancelled("Connection.exec", cancellable);
         var timer = new GLib.Timer();
         throw_on_error("Connection.exec_file", this.db.exec(sql), sql);
         check_elapsed("Query \"%s\"".printf(sql), timer);
@@ -150,6 +151,9 @@ public class Geary.Db.DatabaseConnection : Context, Connection {
     public void exec_file(GLib.File file, GLib.Cancellable? cancellable = null)
         throws GLib.Error {
         check_cancelled("Connection.exec_file", cancellable);
+        if (Db.Context.enable_sql_logging) {
+            debug(file.get_path());
+        }
 
         string sql;
         FileUtils.get_contents(file.get_path(), out sql);
diff --git a/src/engine/db/db-result.vala b/src/engine/db/db-result.vala
index 8c40c475..14dc71a9 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()));
         }
     }
 
-- 
2.29.2