SQL logging: Closes #5288

It's a firehose of log messages, but at least it's available.
This commit is contained in:
Jim Nelson 2012-07-12 17:04:21 -07:00
parent 7fcc8b75db
commit c09a10ddaf
5 changed files with 59 additions and 10 deletions

View file

@ -85,7 +85,7 @@ along with Geary; if not, write to the Free Software Foundation, Inc.,
static bool log_replay_queue = false;
static bool log_conversations = false;
static bool log_periodic = false;
static bool log_transactions = false;
static bool log_sql = false;
static bool version = false;
const OptionEntry[] options = {
{ "debug", 'd', 0, OptionArg.NONE, ref log_debug, N_("Output debugging information"), null },
@ -94,7 +94,7 @@ along with Geary; if not, write to the Free Software Foundation, Inc.,
{ "log-replay-queue", 0, 0, OptionArg.NONE, ref log_replay_queue, N_("Output replay queue log"), null },
{ "log-serializer", 0, 0, OptionArg.NONE, ref log_serializer, N_("Output serializer log"), null },
{ "log-periodic", 0, 0, OptionArg.NONE, ref log_periodic, N_("Output periodic activity"), null },
{ "log-transactions", 0, 0, OptionArg.NONE, ref log_transactions, N_("Output database transactions"), null },
{ "log-sql", 0, 0, OptionArg.NONE, ref log_sql, N_("Output database queries (generates lots of messages)"), null },
{ "version", 'V', 0, OptionArg.NONE, ref version, N_("Display program version"), null },
{ null }
};
@ -135,8 +135,8 @@ along with Geary; if not, write to the Free Software Foundation, Inc.,
if (log_periodic)
Geary.Logging.enable_flags(Geary.Logging.Flag.PERIODIC);
if (log_transactions)
Geary.Logging.enable_flags(Geary.Logging.Flag.TRANSACTIONS);
if (log_sql)
Geary.Logging.enable_flags(Geary.Logging.Flag.SQL);
if (log_debug)
Geary.Logging.log_to(stdout);

View file

@ -14,7 +14,7 @@ public enum Flag {
REPLAY,
CONVERSATIONS,
PERIODIC,
TRANSACTIONS;
SQL;
public inline bool is_all_set(Flag flags) {
return (flags & this) == flags;

View file

@ -25,6 +25,9 @@ public class Geary.Db.Connection : Geary.Db.Context {
private const string PRAGMA_SECURE_DELETE = "secure_delete";
private const string PRAGMA_SYNCHRONOUS = "synchronous";
// this is used for logging purposes only; connection numbers mean nothing to SQLite
private static int next_cx_number = 0;
/**
* See http://www.sqlite.org/c3ref/last_insert_rowid.html
*/
@ -50,11 +53,16 @@ public class Geary.Db.Connection : Geary.Db.Context {
internal Sqlite.Database db;
private int cx_number;
private int busy_timeout_msec = DEFAULT_BUSY_TIMEOUT_MSEC;
internal Connection(Database database, int sqlite_flags, Cancellable? cancellable) throws Error {
this.database = database;
lock (next_cx_number) {
cx_number = next_cx_number++;
}
check_cancelled("Connection.ctor", cancellable);
throw_on_error("Connection.ctor", Sqlite.Database.open_v2(database.db_file.get_path(),
@ -76,6 +84,9 @@ public class Geary.Db.Connection : Geary.Db.Context {
check_cancelled("Connection.exec", cancellable);
throw_on_error("Connection.exec", db.exec(sql), sql);
// Don't use Context.log(), which is designed for logging Results and Statements
Logging.debug(Logging.Flag.SQL, "exec:\n\t%s", sql);
}
/**
@ -330,5 +341,9 @@ public class Geary.Db.Connection : Geary.Db.Context {
public override Connection? get_connection() {
return this;
}
public string to_string() {
return "[%d] %s".printf(cx_number, database.db_file.get_basename());
}
}

View file

@ -32,5 +32,25 @@ public abstract class Geary.Db.Context : Object {
protected inline int throw_on_error(string? method, int result, string? raw = null) throws DatabaseError {
return Db.throw_on_error(this, method, result, raw);
}
[PrintFormat]
protected void log(string fmt, ...) {
if (!Logging.are_all_flags_set(Logging.Flag.SQL))
return;
Connection? cx = get_connection();
Statement? stmt = get_statement();
if (stmt != null) {
Logging.debug(Logging.Flag.SQL, "%s %s\n\t<%s>".printf(
(cx != null) ? cx.to_string() : "[no cx]",
fmt.vprintf(va_list()),
(stmt != null) ? "%.100s".printf(stmt.sql) : "no sql"));
} else {
Logging.debug(Logging.Flag.SQL, "%s %s".printf(
(cx != null) ? cx.to_string() : "[no cx]",
fmt.vprintf(va_list())));
}
}
}

View file

@ -34,8 +34,10 @@ public class Geary.Db.Result : Geary.Db.Context {
public bool next(Cancellable? cancellable = null) throws Error {
check_cancelled("Result.step", cancellable);
if (!finished)
if (!finished) {
finished = (throw_on_error("Result.step", statement.stmt.step())) != Sqlite.ROW;
log(finished ? "NO ROW" : "ROW");
}
return !finished;
}
@ -46,7 +48,10 @@ public class Geary.Db.Result : Geary.Db.Context {
public double double_at(int column) throws DatabaseError {
verify_at(column);
return statement.stmt.column_double(column);
double d = statement.stmt.column_double(column);
log("double_at(%d) -> %lf", column, d);
return d;
}
/**
@ -55,7 +60,10 @@ public class Geary.Db.Result : Geary.Db.Context {
public int int_at(int column) throws DatabaseError {
verify_at(column);
return statement.stmt.column_int(column);
int i = statement.stmt.column_int(column);
log("int_at(%d) -> %d", column, i);
return i;
}
/**
@ -78,7 +86,10 @@ public class Geary.Db.Result : Geary.Db.Context {
public int64 int64_at(int column) throws DatabaseError {
verify_at(column);
return statement.stmt.column_int64(column);
int64 i64 = statement.stmt.column_int64(column);
log("int64_at(%d) -> %s", column, i64.to_string());
return i64;
}
/**
@ -106,7 +117,10 @@ public class Geary.Db.Result : Geary.Db.Context {
public string string_at(int column) throws DatabaseError {
verify_at(column);
return statement.stmt.column_text(column);
string s = statement.stmt.column_text(column);
log("string_at(%d) -> %s", column, s);
return s;
}
private void verify_at(int column) throws DatabaseError {