[sql] Log tag with sqlite errors.

sql/connection.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "sql/connection.h"
 
 #include <string.h>
 
 #include "base/files/file_path.h"
 #include "base/file_util.h"
@@ skipping 623 matching lines @@
 }
 
 bool Connection::Execute(const char* sql) {
   if (!db_) {
     DLOG_IF(FATAL, !poisoned_) << "Illegal use of connection without a db";
     return false;
   }
 
   int error = ExecuteAndReturnErrorCode(sql);
   if (error != SQLITE_OK)
-    error = OnSqliteError(error, NULL);
+    error = OnSqliteError(error, NULL, sql);
 
   // This needs to be a FATAL log because the error case of arriving here is
   // that there's a malformed SQL statement. This can arise in development if
   // a change alters the schema but not all queries adjust.  This can happen
   // in production if the schema is corrupted.
   if (error == SQLITE_ERROR)
     DLOG(FATAL) << "SQL Error in " << sql << ", " << GetErrorMessage();
   return error == SQLITE_OK;
 }
 
@@ skipping 40 matching lines @@
   if (!db_)
     return new StatementRef(NULL, NULL, poisoned_);
 
   sqlite3_stmt* stmt = NULL;
   int rc = sqlite3_prepare_v2(db_, sql, -1, &stmt, NULL);
   if (rc != SQLITE_OK) {
     // This is evidence of a syntax error in the incoming SQL.
     DLOG(FATAL) << "SQL compile error " << GetErrorMessage();
 
     // It could also be database corruption.
-    OnSqliteError(rc, NULL);
+    OnSqliteError(rc, NULL, sql);
     return new StatementRef(NULL, NULL, false);
   }
   return new StatementRef(this, stmt, true);
 }
 
 scoped_refptr<Connection::StatementRef> Connection::GetUntrackedStatement(
     const char* sql) const {
   // Return inactive statement.
   if (!db_)
     return new StatementRef(NULL, NULL, poisoned_);
@@ skipping 141 matching lines @@
   int err = sqlite3_open(file_name.c_str(), &db_);
   if (err != SQLITE_OK) {
     // Extended error codes cannot be enabled until a handle is
     // available, fetch manually.
     err = sqlite3_extended_errcode(db_);
 
     // Histogram failures specific to initial open for debugging
     // purposes.
     UMA_HISTOGRAM_SPARSE_SLOWLY("Sqlite.OpenFailure", err);
 
-    OnSqliteError(err, NULL);
+    OnSqliteError(err, NULL, "-- sqlite3_open()");
     bool was_poisoned = poisoned_;
     Close();
 
     if (was_poisoned && retry_flag == RETRY_ON_POISON)
       return OpenInternal(file_name, NO_RETRY);
     return false;
   }
 
   // TODO(shess): OS_WIN support?
 #if defined(OS_POSIX)
@@ skipping 137 matching lines @@
   // issue, the object could be cached alongside histogram_prefix_.
   std::string full_histogram_name = name + "." + histogram_tag_;
   base::HistogramBase* histogram =
       base::SparseHistogram::FactoryGet(
           full_histogram_name,
           base::HistogramBase::kUmaTargetedHistogramFlag);
   if (histogram)
     histogram->Add(sample);
 }
 
-int Connection::OnSqliteError(int err, sql::Statement *stmt) {
+int Connection::OnSqliteError(int err, sql::Statement *stmt, const char* sql) {
   UMA_HISTOGRAM_SPARSE_SLOWLY("Sqlite.Error", err);
   AddTaggedHistogram("Sqlite.Error", err);
 
   // Always log the error.
-  LOG(ERROR) << "sqlite error " << err
+  LOG(ERROR) << histogram_tag_ << " sqlite error " << err
              << ", errno " << GetLastErrno()
              << ": " << GetErrorMessage();
 
+  // Also log the relevant sql statement, if possible.
+  if (!sql && stmt)
+    sql = stmt->GetSQLStatement();
+  if (sql)
+    LOG(ERROR) << "sql: " << sql;

[Greg Spencer (Chromium), 2013/09/25 20:01:18]

nits: You might want to also output "sqlite error" as part of this message so
that they're easier to grep for.  It might also be nice to merge this with the
line above so that all information is on one line to keep from having
interleaved messages from other threads.  That might be too much on one line
though.

[Scott Hess - ex-Googler, 2013/09/25 20:22:36]

I'm moving it up to the same line, just to be safe.  Possibly things will get
trimmed for very long lines, but it should narrow things down a lot even in
those cases.

+
   if (!error_callback_.is_null()) {
     // Fire from a copy of the callback in case of reentry into
     // re/set_error_callback().
     // TODO(shess): <http://crbug.com/254584>
     ErrorCallback(error_callback_).Run(err, stmt);
     return err;
   }
 
   // The default handling is to assert on debug and to ignore on release.
   if (!ShouldIgnore(err))
@@ skipping 30 matching lines @@
   }
 
   // Best effort to put things back as they were before.
   const char kNoWritableSchema[] = "PRAGMA writable_schema = OFF";
   ignore_result(Execute(kNoWritableSchema));
 
   return ret;
 }
 
 }  // namespace sql