[sql] Stats gathering for sql/ APIs.

sql/statement.cc

Index: sql/statement.cc
diff --git a/sql/statement.cc b/sql/statement.cc
index 42b4598c51da87bcc6037446dc7e1d6970ab5153..3b0a81f863ac71998750016890cd1ddf28c88304 100644
--- a/sql/statement.cc
+++ b/sql/statement.cc
@@ -51,34 +51,57 @@ bool Statement::CheckValid() const {
   return is_valid();
 }
 
-bool Statement::Run() {
-  DCHECK(!stepped_);
+int Statement::InnerStep(bool timer_flag) {
   ref_->AssertIOAllowed();
   if (!CheckValid())
-    return false;
+    return SQLITE_ERROR;
 
+  const bool was_stepped = stepped_;
   stepped_ = true;
-  return CheckError(sqlite3_step(ref_->stmt())) == SQLITE_DONE;
+  const base::TimeTicks before = base::TimeTicks::Now();

[rmcilroy, 2015/05/21 22:54:48]

You should probably only call base::TimerTicks::Now() if timer_flag is true and
you are going to use the result - it can be costly on some platforms.

[Scott Hess - ex-Googler, 2015/05/21 23:42:37]

Ugh, that maybe makes the logic icky because of the independent stack variables.
 I've shifted it to conditionally use base::TimeTicks::TimeTicks(), it's not
pretty, but I don't think there would be a performance downside.

How costly is costly?  Costly enough to make the overall approach questionable? 
I've been working under the assumption that measuring everything should be a
small fraction of the costs involved, but it would probably be fine to use
random sampling.

[rmcilroy, 2015/05/22 08:48:23]

Jared put together a list showing the cost of various operations on Android
(linked below) which show Now() as being 0.8 micro seconds (~4x a lock
operation) - I'm assuming this is fairly neglegable compared to the sql stuff
but just wanted to avoid doubling the overhead here.

https://docs.google.com/a/google.com/spreadsheets/d/1ulggKOZ7VQ8IytP1hKr-1wvB...

+  int ret = sqlite3_step(ref_->stmt());
+  const base::TimeDelta delta = base::TimeTicks::Now() - before;
+  if (ref_->connection()) {
+    if (timer_flag) {
+      const int read_only = sqlite3_stmt_readonly(ref_->stmt());
+      ref_->connection()->ChangeHelper(delta, read_only);
+    }
+
+    if (!was_stepped)
+      ref_->connection()->RecordOneEvent(Connection::EVENT_STATEMENT_RUN);
+
+    if (ret == SQLITE_ROW)
+      ref_->connection()->RecordOneEvent(Connection::EVENT_STATEMENT_ROWS);
+  }
+  return CheckError(ret);
 }
 
-bool Statement::Step() {
-  ref_->AssertIOAllowed();
-  if (!CheckValid())
-    return false;
+bool Statement::Run() {
+  DCHECK(!stepped_);
+  return InnerStep(true) == SQLITE_DONE;
+}
 
-  stepped_ = true;
-  return CheckError(sqlite3_step(ref_->stmt())) == SQLITE_ROW;
+bool Statement::RunWithoutTimers() {
+  DCHECK(!stepped_);
+  return InnerStep(false) == SQLITE_DONE;
+}
+
+bool Statement::Step() {
+  return InnerStep(true) == SQLITE_ROW;
 }
 
 void Statement::Reset(bool clear_bound_vars) {
   ref_->AssertIOAllowed();
   if (is_valid()) {
-    // We don't call CheckError() here because sqlite3_reset() returns
-    // the last error that Step() caused thereby generating a second
-    // spurious error callback.
     if (clear_bound_vars)
       sqlite3_clear_bindings(ref_->stmt());
-    sqlite3_reset(ref_->stmt());
+
+    // InnerStep() cannot track success because statements may be reset before
+    // reaching SQLITE_DONE.  Don't call CheckError() because sqlite3_reset()
+    // returns the last step error, which InnerStep() already checked.
+    const int rc =sqlite3_reset(ref_->stmt());
+    if (rc == SQLITE_OK && ref_->connection())
+      ref_->connection()->RecordOneEvent(Connection::EVENT_STATEMENT_SUCCESS);
   }
 
   succeeded_ = false;