[sql] Track uploads of diagnostic data to prevent duplication.

The ThumbnailDatabase error handler attempts to capture generic data
about the error, which is then uploaded for diagnostics with
DumpWithoutCrashing().  Database with errors which are not repaired
upload new dumps repeatedly.  This change adds a tracking file alongside
the database file, which has the dual purpose of recording whether a
previous dump was attempted, and also verifying that files can be
created in the profile directory.  If the profile directory is too
broken to create files, then diagnostic data is unlikely to inform a
fix.

BUG=543321,362505,526614,240396

Review URL: https://codereview.chromium.org/1393393007

Cr-Commit-Position: refs/heads/master@{#355632}

3 files changed, 407 insertions, 24 deletions

diff --git a/sql/connection.cc b/sql/connection.cc
index 61aebbe..669344a 100644
--- a/sql/connection.cc
+++ b/sql/connection.cc
@@ -7,8 +7,11 @@
 #include <string.h>
 
 #include "base/bind.h"
+#include "base/debug/dump_without_crashing.h"
 #include "base/files/file_path.h"
 #include "base/files/file_util.h"
+#include "base/format_macros.h"
+#include "base/json/json_file_value_serializer.h"
 #include "base/lazy_instance.h"
 #include "base/logging.h"
 #include "base/message_loop/message_loop.h"
@@ -257,6 +260,26 @@ bool Connection::OnMemoryDump(const base::trace_event::MemoryDumpArgs& args,
   return true;
 }
 
+void Connection::ReportDiagnosticInfo(int extended_error, Statement* stmt) {
+  AssertIOAllowed();
+
+  std::string debug_info;
+  const int error = (extended_error & 0xFF);
+  if (error == SQLITE_CORRUPT) {
+    debug_info = CollectCorruptionInfo();
+  } else {
+    debug_info = CollectErrorInfo(extended_error, stmt);
+  }
+
+  if (!debug_info.empty() && RegisterIntentToUpload()) {
+    char debug_buf[2000];
+    base::strlcpy(debug_buf, debug_info.c_str(), arraysize(debug_buf));
+    base::debug::Alias(&debug_buf);
+
+    base::debug::DumpWithoutCrashing();
+  }
+}
+
 // static
 void Connection::SetErrorIgnorer(Connection::ErrorIgnorerCallback* cb) {
   CHECK(current_ignorer_cb_ == NULL);
@@ -582,6 +605,256 @@ void Connection::ReleaseCacheMemoryIfNeeded(bool implicit_change_performed) {
   sqlite3_db_release_memory(db_);
 }
 
+base::FilePath Connection::DbPath() const {
+  if (!is_open())
+    return base::FilePath();
+
+  const char* path = sqlite3_db_filename(db_, "main");
+  const base::StringPiece db_path(path);
+#if defined(OS_WIN)
+  return base::FilePath(base::UTF8ToWide(db_path));
+#elif defined(OS_POSIX)
+  return base::FilePath(db_path);
+#else
+  NOTREACHED();
+  return base::FilePath();
+#endif
+}
+
+// Data is persisted in a file shared between databases in the same directory.
+// The "sqlite-diag" file contains a dictionary with the version number, and an
+// array of histogram tags for databases which have been dumped.
+bool Connection::RegisterIntentToUpload() const {
+  static const char* kVersionKey = "version";
+  static const char* kDiagnosticDumpsKey = "DiagnosticDumps";
+  static int kVersion = 1;
+
+  AssertIOAllowed();
+
+  if (histogram_tag_.empty())
+    return false;
+
+  if (!is_open())
+    return false;
+
+  if (in_memory_)
+    return false;
+
+  const base::FilePath db_path = DbPath();
+  if (db_path.empty())
+    return false;
+
+  // Put the collection of diagnostic data next to the databases.  In most
+  // cases, this is the profile directory, but safe-browsing stores a Cookies
+  // file in the directory above the profile directory.
+  base::FilePath breadcrumb_path(
+      db_path.DirName().Append(FILE_PATH_LITERAL("sqlite-diag")));
+
+  // Lock against multiple updates to the diagnostics file.  This code should
+  // seldom be called in the first place, and when called it should seldom be
+  // called for multiple databases, and when called for multiple databases there
+  // is _probably_ something systemic wrong with the user's system.  So the lock
+  // should never be contended, but when it is the database experience is
+  // already bad.
+  base::AutoLock lock(g_sqlite_init_lock.Get());
+
+  scoped_ptr<base::Value> root;
+  if (!base::PathExists(breadcrumb_path)) {
+    scoped_ptr<base::DictionaryValue> root_dict(new base::DictionaryValue());
+    root_dict->SetInteger(kVersionKey, kVersion);
+
+    scoped_ptr<base::ListValue> dumps(new base::ListValue);
+    dumps->AppendString(histogram_tag_);
+    root_dict->Set(kDiagnosticDumpsKey, dumps.Pass());
+
+    root = root_dict.Pass();
+  } else {
+    // Failure to read a valid dictionary implies that something is going wrong
+    // on the system.
+    JSONFileValueDeserializer deserializer(breadcrumb_path);
+    scoped_ptr<base::Value> read_root(
+        deserializer.Deserialize(nullptr, nullptr));
+    if (!read_root.get())
+      return false;
+    scoped_ptr<base::DictionaryValue> root_dict =
+        base::DictionaryValue::From(read_root.Pass());
+    if (!root_dict)
+      return false;
+
+    // Don't upload if the version is missing or newer.
+    int version = 0;
+    if (!root_dict->GetInteger(kVersionKey, &version) || version > kVersion)
+      return false;
+
+    base::ListValue* dumps = nullptr;
+    if (!root_dict->GetList(kDiagnosticDumpsKey, &dumps))
+      return false;
+
+    const size_t size = dumps->GetSize();
+    for (size_t i = 0; i < size; ++i) {
+      std::string s;
+
+      // Don't upload if the value isn't a string, or indicates a prior upload.
+      if (!dumps->GetString(i, &s) || s == histogram_tag_)
+        return false;
+    }
+
+    // Record intention to proceed with upload.
+    dumps->AppendString(histogram_tag_);
+    root = root_dict.Pass();
+  }
+
+  const base::FilePath breadcrumb_new =
+      breadcrumb_path.AddExtension(FILE_PATH_LITERAL("new"));
+  base::DeleteFile(breadcrumb_new, false);
+
+  // No upload if the breadcrumb file cannot be updated.
+  // TODO(shess): Consider ImportantFileWriter::WriteFileAtomically() to land
+  // the data on disk.  For now, losing the data is not a big problem, so the
+  // sync overhead would probably not be worth it.
+  JSONFileValueSerializer serializer(breadcrumb_new);
+  if (!serializer.Serialize(*root))
+    return false;
+  if (!base::PathExists(breadcrumb_new))
+    return false;
+  if (!base::ReplaceFile(breadcrumb_new, breadcrumb_path, nullptr)) {
+    base::DeleteFile(breadcrumb_new, false);
+    return false;
+  }
+
+  return true;
+}
+
+std::string Connection::CollectErrorInfo(int error, Statement* stmt) const {
+  // Buffer for accumulating debugging info about the error.  Place
+  // more-relevant information earlier, in case things overflow the
+  // fixed-size reporting buffer.
+  std::string debug_info;
+
+  // The error message from the failed operation.
+  base::StringAppendF(&debug_info, "db error: %d/%s\n",
+                      GetErrorCode(), GetErrorMessage());
+
+  // TODO(shess): |error| and |GetErrorCode()| should always be the same, but
+  // reading code does not entirely convince me.  Remove if they turn out to be
+  // the same.
+  if (error != GetErrorCode())
+    base::StringAppendF(&debug_info, "reported error: %d\n", error);
+
+  // System error information.  Interpretation of Windows errors is different
+  // from posix.
+#if defined(OS_WIN)
+  base::StringAppendF(&debug_info, "LastError: %d\n", GetLastErrno());
+#elif defined(OS_POSIX)
+  base::StringAppendF(&debug_info, "errno: %d\n", GetLastErrno());
+#else
+  NOTREACHED();  // Add appropriate log info.
+#endif
+
+  if (stmt) {
+    base::StringAppendF(&debug_info, "statement: %s\n",
+                        stmt->GetSQLStatement());
+  } else {
+    base::StringAppendF(&debug_info, "statement: NULL\n");
+  }
+
+  // SQLITE_ERROR often indicates some sort of mismatch between the statement
+  // and the schema, possibly due to a failed schema migration.
+  if (error == SQLITE_ERROR) {
+    const char* kVersionSql = "SELECT value FROM meta WHERE key = 'version'";
+    sqlite3_stmt* s;
+    int rc = sqlite3_prepare_v2(db_, kVersionSql, -1, &s, nullptr);
+    if (rc == SQLITE_OK) {
+      rc = sqlite3_step(s);
+      if (rc == SQLITE_ROW) {
+        base::StringAppendF(&debug_info, "version: %d\n",
+                            sqlite3_column_int(s, 0));
+      } else if (rc == SQLITE_DONE) {
+        debug_info += "version: none\n";
+      } else {
+        base::StringAppendF(&debug_info, "version: error %d\n", rc);
+      }
+      sqlite3_finalize(s);
+    } else {
+      base::StringAppendF(&debug_info, "version: prepare error %d\n", rc);
+    }
+
+    debug_info += "schema:\n";
+
+    // sqlite_master has columns:
+    //   type - "index" or "table".
+    //   name - name of created element.
+    //   tbl_name - name of element, or target table in case of index.
+    //   rootpage - root page of the element in database file.
+    //   sql - SQL to create the element.
+    // In general, the |sql| column is sufficient to derive the other columns.
+    // |rootpage| is not interesting for debugging, without the contents of the
+    // database.  The COALESCE is because certain automatic elements will have a
+    // |name| but no |sql|,
+    const char* kSchemaSql = "SELECT COALESCE(sql, name) FROM sqlite_master";
+    rc = sqlite3_prepare_v2(db_, kSchemaSql, -1, &s, nullptr);
+    if (rc == SQLITE_OK) {
+      while ((rc = sqlite3_step(s)) == SQLITE_ROW) {
+        base::StringAppendF(&debug_info, "%s\n", sqlite3_column_text(s, 0));
+      }
+      if (rc != SQLITE_DONE)
+        base::StringAppendF(&debug_info, "error %d\n", rc);
+      sqlite3_finalize(s);
+    } else {
+      base::StringAppendF(&debug_info, "prepare error %d\n", rc);
+    }
+  }
+
+  return debug_info;
+}
+
+// TODO(shess): Since this is only called in an error situation, it might be
+// prudent to rewrite in terms of SQLite API calls, and mark the function const.
+std::string Connection::CollectCorruptionInfo() {
+  AssertIOAllowed();
+
+  // If the file cannot be accessed it is unlikely that an integrity check will
+  // turn up actionable information.
+  const base::FilePath db_path = DbPath();
+  int64 db_size = -1;
+  if (!base::GetFileSize(db_path, &db_size) || db_size < 0)
+    return std::string();
+
+  // Buffer for accumulating debugging info about the error.  Place
+  // more-relevant information earlier, in case things overflow the
+  // fixed-size reporting buffer.
+  std::string debug_info;
+  base::StringAppendF(&debug_info, "SQLITE_CORRUPT, db size %" PRId64 "\n",
+                      db_size);
+
+  // Only check files up to 8M to keep things from blocking too long.
+  const int64 kMaxIntegrityCheckSize = 8192 * 1024;
+  if (db_size > kMaxIntegrityCheckSize) {
+    debug_info += "integrity_check skipped due to size\n";
+  } else {
+    std::vector<std::string> messages;
+
+    // TODO(shess): FullIntegrityCheck() splits into a vector while this joins
+    // into a string.  Probably should be refactored.
+    const base::TimeTicks before = base::TimeTicks::Now();
+    FullIntegrityCheck(&messages);
+    base::StringAppendF(
+        &debug_info,
+        "integrity_check %" PRId64 " ms, %" PRIuS " records:\n",
+        (base::TimeTicks::Now() - before).InMilliseconds(),
+        messages.size());
+
+    // SQLite returns up to 100 messages by default, trim deeper to
+    // keep close to the 2000-character size limit for dumping.
+    const size_t kMaxMessages = 20;
+    for (size_t i = 0; i < kMaxMessages && i < messages.size(); ++i) {
+      base::StringAppendF(&debug_info, "%s\n", messages[i].c_str());
+    }
+  }
+
+  return debug_info;
+}
+
 void Connection::TrimMemory(bool aggressively) {
   if (!db_)
     return;
diff --git a/sql/connection.h b/sql/connection.h
index 7d2ab6a..4e3ce26 100644
--- a/sql/connection.h
+++ b/sql/connection.h
@@ -13,6 +13,7 @@
 
 #include "base/callback.h"
 #include "base/compiler_specific.h"
+#include "base/gtest_prod_util.h"
 #include "base/macros.h"
 #include "base/memory/ref_counted.h"
 #include "base/memory/scoped_ptr.h"
@@ -470,6 +471,11 @@ class SQL_EXPORT Connection : public base::trace_event::MemoryDumpProvider {
       const base::trace_event::MemoryDumpArgs& args,
       base::trace_event::ProcessMemoryDump* process_memory_dump) override;
 
+  // Collect various diagnostic information and post a crash dump to aid
+  // debugging.  Dump rate per database is limited to prevent overwhelming the
+  // crash server.
+  void ReportDiagnosticInfo(int extended_error, Statement* stmt);
+
  private:
   // For recovery module.
   friend class Recovery;
@@ -485,6 +491,9 @@ class SQL_EXPORT Connection : public base::trace_event::MemoryDumpProvider {
   friend class test::ScopedScalarFunction;
   friend class test::ScopedMockTimeSource;
 
+  FRIEND_TEST_ALL_PREFIXES(SQLConnectionTest, CollectDiagnosticInfo);
+  FRIEND_TEST_ALL_PREFIXES(SQLConnectionTest, RegisterIntentToUpload);
+
   // Internal initialize function used by both Init and InitInMemory. The file
   // name is always 8 bits since we want to use the 8-bit version of
   // sqlite3_open. The string can also be sqlite's special ":memory:" string.
@@ -504,7 +513,7 @@ class SQL_EXPORT Connection : public base::trace_event::MemoryDumpProvider {
   // Check whether the current thread is allowed to make IO calls, but only
   // if database wasn't open in memory. Function is inlined to be a no-op in
   // official build.
-  void AssertIOAllowed() {
+  void AssertIOAllowed() const {
     if (!in_memory_)
       base::ThreadRestrictions::AssertIOAllowed();
   }
@@ -653,6 +662,33 @@ class SQL_EXPORT Connection : public base::trace_event::MemoryDumpProvider {
   // which do not participate in the total-rows-changed tracking.
   void ReleaseCacheMemoryIfNeeded(bool implicit_change_performed);
 
+  // Returns the results of sqlite3_db_filename(), which should match the path
+  // passed to Open().
+  base::FilePath DbPath() const;
+
+  // Helper to prevent uploading too many diagnostic dumps for a given database,
+  // since every dump will likely show the same problem.  Returns |true| if this
+  // function was not previously called for this database, and the persistent
+  // storage which tracks state was updated.
+  //
+  // |false| is returned if the function was previously called for this
+  // database, even across restarts.  |false| is also returned if the persistent
+  // storage cannot be updated, possibly indicating problems requiring user or
+  // admin intervention, such as filesystem corruption or disk full.  |false| is
+  // also returned if the persistent storage contains invalid data or is not
+  // readable.
+  //
+  // TODO(shess): It would make sense to reset the persistent state if the
+  // database is razed or recovered, or if the diagnostic code adds new
+  // capabilities.
+  bool RegisterIntentToUpload() const;
+
+  // Helper to collect diagnostic info for a corrupt database.
+  std::string CollectCorruptionInfo();
+
+  // Helper to collect diagnostic info for errors.
+  std::string CollectErrorInfo(int error, Statement* stmt) const;
+
   // The actual sqlite database. Will be NULL before Init has been called or if
   // Init resulted in an error.
   sqlite3* db_;
diff --git a/sql/connection_unittest.cc b/sql/connection_unittest.cc
index d933a6d..7e9d41e 100644
--- a/sql/connection_unittest.cc
+++ b/sql/connection_unittest.cc
@@ -136,7 +136,6 @@ class ScopedCommitHook {
 };
 
 }  // namespace test
-}  // namespace sql
 
 namespace {
 
@@ -210,6 +209,29 @@ class ScopedUmaskSetter {
 };
 #endif
 
+// SQLite function to adjust mock time by |argv[0]| milliseconds.
+void sqlite_adjust_millis(sql::test::ScopedMockTimeSource* time_mock,
+                          sqlite3_context* context,
+                          int argc, sqlite3_value** argv) {
+  int64 milliseconds = argc > 0 ? sqlite3_value_int64(argv[0]) : 1000;
+  time_mock->adjust(base::TimeDelta::FromMilliseconds(milliseconds));
+  sqlite3_result_int64(context, milliseconds);
+}
+
+// Adjust mock time by |milliseconds| on commit.
+int adjust_commit_hook(sql::test::ScopedMockTimeSource* time_mock,
+                       int64 milliseconds) {
+  time_mock->adjust(base::TimeDelta::FromMilliseconds(milliseconds));
+  return SQLITE_OK;
+}
+
+const char kCommitTime[] = "Sqlite.CommitTime.Test";
+const char kAutoCommitTime[] = "Sqlite.AutoCommitTime.Test";
+const char kUpdateTime[] = "Sqlite.UpdateTime.Test";
+const char kQueryTime[] = "Sqlite.QueryTime.Test";
+
+}  // namespace
+
 class SQLConnectionTest : public sql::SQLTestBase {
  public:
   void SetUp() override {
@@ -1147,27 +1169,6 @@ TEST_F(SQLConnectionTest, EventsStatement) {
   }
 }
 
-// SQLite function to adjust mock time by |argv[0]| milliseconds.
-void sqlite_adjust_millis(sql::test::ScopedMockTimeSource* time_mock,
-                          sqlite3_context* context,
-                          int argc, sqlite3_value** argv) {
-  int64 milliseconds = argc > 0 ? sqlite3_value_int64(argv[0]) : 1000;
-  time_mock->adjust(base::TimeDelta::FromMilliseconds(milliseconds));
-  sqlite3_result_int64(context, milliseconds);
-}
-
-// Adjust mock time by |milliseconds| on commit.
-int adjust_commit_hook(sql::test::ScopedMockTimeSource* time_mock,
-                       int64 milliseconds) {
-  time_mock->adjust(base::TimeDelta::FromMilliseconds(milliseconds));
-  return SQLITE_OK;
-}
-
-const char kCommitTime[] = "Sqlite.CommitTime.Test";
-const char kAutoCommitTime[] = "Sqlite.AutoCommitTime.Test";
-const char kUpdateTime[] = "Sqlite.UpdateTime.Test";
-const char kQueryTime[] = "Sqlite.QueryTime.Test";
-
 // Read-only query allocates time to QueryTime, but not others.
 TEST_F(SQLConnectionTest, TimeQuery) {
   // Re-open with histogram tag.  Use an in-memory database to minimize variance
@@ -1387,4 +1388,77 @@ TEST_F(SQLConnectionTest, OnMemoryDump) {
   EXPECT_GE(pmd.allocator_dumps().size(), 1u);
 }
 
-}  // namespace
+// Test that the functions to collect diagnostic data run to completion, without
+// worrying too much about what they generate (since that will change).
+TEST_F(SQLConnectionTest, CollectDiagnosticInfo) {
+  // NOTE(shess): Mojo doesn't support everything CollectCorruptionInfo() uses,
+  // but it's not really clear if adding support would be useful.
+#if !defined(MOJO_APPTEST_IMPL)
+  const std::string corruption_info = db().CollectCorruptionInfo();
+  EXPECT_NE(std::string::npos, corruption_info.find("SQLITE_CORRUPT"));
+  EXPECT_NE(std::string::npos, corruption_info.find("integrity_check"));
+#endif
+
+  // A statement to see in the results.
+  const char* kSimpleSql = "SELECT 'mountain'";
+  Statement s(db().GetCachedStatement(SQL_FROM_HERE, kSimpleSql));
+
+  // Error includes the statement.
+  const std::string readonly_info = db().CollectErrorInfo(SQLITE_READONLY, &s);
+  EXPECT_NE(std::string::npos, readonly_info.find(kSimpleSql));
+
+  // Some other error doesn't include the statment.
+  // TODO(shess): This is weak.
+  const std::string full_info = db().CollectErrorInfo(SQLITE_FULL, NULL);
+  EXPECT_EQ(std::string::npos, full_info.find(kSimpleSql));
+
+  // A table to see in the SQLITE_ERROR results.
+  EXPECT_TRUE(db().Execute("CREATE TABLE volcano (x)"));
+
+  // Version info to see in the SQLITE_ERROR results.
+  sql::MetaTable meta_table;
+  ASSERT_TRUE(meta_table.Init(&db(), 4, 4));
+
+  const std::string error_info = db().CollectErrorInfo(SQLITE_ERROR, &s);
+  EXPECT_NE(std::string::npos, error_info.find(kSimpleSql));
+  EXPECT_NE(std::string::npos, error_info.find("volcano"));
+  EXPECT_NE(std::string::npos, error_info.find("version: 4"));
+}
+
+#if !defined(MOJO_APPTEST_IMPL)
+TEST_F(SQLConnectionTest, RegisterIntentToUpload) {
+  base::FilePath breadcrumb_path(
+      db_path().DirName().Append(FILE_PATH_LITERAL("sqlite-diag")));
+
+  // No stale diagnostic store.
+  ASSERT_TRUE(!base::PathExists(breadcrumb_path));
+
+  // The histogram tag is required to enable diagnostic features.
+  EXPECT_FALSE(db().RegisterIntentToUpload());
+  EXPECT_TRUE(!base::PathExists(breadcrumb_path));
+
+  db().Close();
+  db().set_histogram_tag("Test");
+  ASSERT_TRUE(db().Open(db_path()));
+
+  // Should signal upload only once.
+  EXPECT_TRUE(db().RegisterIntentToUpload());
+  EXPECT_TRUE(base::PathExists(breadcrumb_path));
+  EXPECT_FALSE(db().RegisterIntentToUpload());
+
+  // Changing the histogram tag should allow new upload to succeed.
+  db().Close();
+  db().set_histogram_tag("NewTest");
+  ASSERT_TRUE(db().Open(db_path()));
+  EXPECT_TRUE(db().RegisterIntentToUpload());
+  EXPECT_FALSE(db().RegisterIntentToUpload());
+
+  // Old tag is still prevented.
+  db().Close();
+  db().set_histogram_tag("Test");
+  ASSERT_TRUE(db().Open(db_path()));
+  EXPECT_FALSE(db().RegisterIntentToUpload());
+}
+#endif  // !defined(MOJO_APPTEST_IMPL)
+
+}  // namespace sql