Bug 1635489: Add telemetry on the status of sqlite database accesses.…

… r=mak Includes baddataDB.sqlite which is a copy of goodDB.sqlite but with what appears to be the row count inflated beyond the end of the file. This causes loading the database to succeed but queries to fail. This increments a scalar for every database open and for every database query where a query is the full execution of a statement from start to completion. If a statement is re-used then the scalar will be incremented once for each use. Differential Revision: https://phabricator.services.mozilla.com/D73938
kush930 · Aug 11, 2020 · c906168 · c906168
1 parent c3f53ee
commit c906168
Show file tree

Hide file tree

Showing 20 changed files with 633 additions and 90 deletions.
diff --git a/dom/cache/DBAction.cpp b/dom/cache/DBAction.cpp
@@ -226,7 +226,8 @@ nsresult OpenDBConnection(const QuotaInfo& aQuotaInfo, nsIFile* aDBFile,
   }
 
   nsCOMPtr<mozIStorageConnection> conn;
-  rv = ss->OpenDatabaseWithFileURL(dbFileUrl, getter_AddRefs(conn));
+  rv = ss->OpenDatabaseWithFileURL(dbFileUrl, EmptyCString(),
+                                   getter_AddRefs(conn));
   if (rv == NS_ERROR_FILE_CORRUPTED) {
     NS_WARNING("Cache database corrupted. Recreating empty database.");
 
@@ -239,7 +240,8 @@ nsresult OpenDBConnection(const QuotaInfo& aQuotaInfo, nsIFile* aDBFile,
       return rv;
     }
 
-    rv = ss->OpenDatabaseWithFileURL(dbFileUrl, getter_AddRefs(conn));
+    rv = ss->OpenDatabaseWithFileURL(dbFileUrl, EmptyCString(),
+                                     getter_AddRefs(conn));
   }
   if (NS_WARN_IF(NS_FAILED(rv))) {
     return rv;
@@ -258,7 +260,8 @@ nsresult OpenDBConnection(const QuotaInfo& aQuotaInfo, nsIFile* aDBFile,
       return rv;
     }
 
-    rv = ss->OpenDatabaseWithFileURL(dbFileUrl, getter_AddRefs(conn));
+    rv = ss->OpenDatabaseWithFileURL(dbFileUrl, EmptyCString(),
+                                     getter_AddRefs(conn));
     if (NS_WARN_IF(NS_FAILED(rv))) {
       return rv;
     }

diff --git a/dom/indexedDB/ActorsParent.cpp b/dom/indexedDB/ActorsParent.cpp
@@ -3806,8 +3806,7 @@ nsresult UpgradeSchemaFrom25_0To26_0(mozIStorageConnection& aConnection) {
 }
 
 Result<nsCOMPtr<nsIFileURL>, nsresult> GetDatabaseFileURL(
-    nsIFile& aDatabaseFile, const int64_t aDirectoryLockId,
-    const uint32_t aTelemetryId) {
+    nsIFile& aDatabaseFile, const int64_t aDirectoryLockId) {
   MOZ_ASSERT(aDirectoryLockId >= -1);
 
   nsresult rv;
@@ -3840,17 +3839,9 @@ Result<nsCOMPtr<nsIFileURL>, nsresult> GetDatabaseFileURL(
           ? "&directoryLockId="_ns + IntCString(aDirectoryLockId)
           : EmptyCString();
 
-  nsAutoCString telemetryFilenameClause;
-  if (aTelemetryId) {
-    telemetryFilenameClause.AssignLiteral("&telemetryFilename=indexedDB-");
-    telemetryFilenameClause.AppendInt(aTelemetryId);
-    telemetryFilenameClause.Append(NS_ConvertUTF16toUTF8(kSQLiteSuffix));
-  }
-
   nsCOMPtr<nsIFileURL> result;
   rv = NS_MutateURI(mutator)
-           .SetQuery("cache=private"_ns + directoryLockIdClause +
-                     telemetryFilenameClause)
+           .SetQuery("cache=private"_ns + directoryLockIdClause)
            .Finalize(result);
   if (NS_WARN_IF(NS_FAILED(rv))) {
     return Err(rv);
@@ -3984,10 +3975,18 @@ struct StorageOpenTraits;
 template <>
 struct StorageOpenTraits<nsIFileURL> {
   static Result<MovingNotNull<nsCOMPtr<mozIStorageConnection>>, nsresult> Open(
-      mozIStorageService& aStorageService, nsIFileURL& aFileURL) {
+      mozIStorageService& aStorageService, nsIFileURL& aFileURL,
+      const uint32_t aTelemetryId = 0) {
+    nsAutoCString telemetryFilename;
+    if (aTelemetryId) {
+      telemetryFilename.AssignLiteral("indexedDB-");
+      telemetryFilename.AppendInt(aTelemetryId);
+      telemetryFilename.Append(NS_ConvertUTF16toUTF8(kSQLiteSuffix));
+    }
+
     nsCOMPtr<mozIStorageConnection> connection;
     nsresult rv = aStorageService.OpenDatabaseWithFileURL(
-        &aFileURL, getter_AddRefs(connection));
+        &aFileURL, telemetryFilename, getter_AddRefs(connection));
     return ValOrErr(std::move(connection), rv);
   }
 
@@ -4001,7 +4000,8 @@ struct StorageOpenTraits<nsIFileURL> {
 template <>
 struct StorageOpenTraits<nsIFile> {
   static Result<MovingNotNull<nsCOMPtr<mozIStorageConnection>>, nsresult> Open(
-      mozIStorageService& aStorageService, nsIFile& aFile) {
+      mozIStorageService& aStorageService, nsIFile& aFile,
+      const uint32_t aTelemetryId = 0) {
     nsCOMPtr<mozIStorageConnection> connection;
     nsresult rv = aStorageService.OpenUnsharedDatabase(
         &aFile, getter_AddRefs(connection));
@@ -4021,12 +4021,13 @@ struct StorageOpenTraits<nsIFile> {
 template <class FileOrURLType>
 Result<MovingNotNull<nsCOMPtr<mozIStorageConnection>>, nsresult>
 OpenDatabaseAndHandleBusy(mozIStorageService& aStorageService,
-                          FileOrURLType& aFileOrURL) {
+                          FileOrURLType& aFileOrURL,
+                          const uint32_t aTelemetryId = 0) {
   MOZ_ASSERT(!NS_IsMainThread());
   MOZ_ASSERT(!IsOnBackgroundThread());
 
-  auto connectionOrErr =
-      StorageOpenTraits<FileOrURLType>::Open(aStorageService, aFileOrURL);
+  auto connectionOrErr = StorageOpenTraits<FileOrURLType>::Open(
+      aStorageService, aFileOrURL, aTelemetryId);
 
   if (connectionOrErr.isErr() &&
       connectionOrErr.inspectErr() == NS_ERROR_STORAGE_BUSY) {
@@ -4051,8 +4052,8 @@ OpenDatabaseAndHandleBusy(mozIStorageService& aStorageService,
     while (true) {
       PR_Sleep(PR_MillisecondsToInterval(100));
 
-      connectionOrErr =
-          StorageOpenTraits<FileOrURLType>::Open(aStorageService, aFileOrURL);
+      connectionOrErr = StorageOpenTraits<FileOrURLType>::Open(
+          aStorageService, aFileOrURL, aTelemetryId);
       if (!connectionOrErr.isErr() ||
           connectionOrErr.inspectErr() != NS_ERROR_STORAGE_BUSY ||
           TimeStamp::NowLoRes() - start > TimeDuration::FromSeconds(10)) {
@@ -4080,8 +4081,7 @@ CreateStorageConnection(nsIFile& aDBFile, nsIFile& aFMDirectory,
 
   bool exists;
 
-  auto dbFileUrlOrErr =
-      GetDatabaseFileURL(aDBFile, aDirectoryLockId, aTelemetryId);
+  auto dbFileUrlOrErr = GetDatabaseFileURL(aDBFile, aDirectoryLockId);
   if (NS_WARN_IF(dbFileUrlOrErr.isErr())) {
     return dbFileUrlOrErr.propagateErr();
   }
@@ -4095,7 +4095,8 @@ CreateStorageConnection(nsIFile& aDBFile, nsIFile& aFMDirectory,
     return Err(rv);
   }
 
-  auto connectionOrErr = OpenDatabaseAndHandleBusy(*ss, *dbFileUrl);
+  auto connectionOrErr =
+      OpenDatabaseAndHandleBusy(*ss, *dbFileUrl, aTelemetryId);
   if (connectionOrErr.isErr()) {
     if (connectionOrErr.inspectErr() == NS_ERROR_FILE_CORRUPTED) {
       // If we're just opening the database during origin initialization, then
@@ -4133,7 +4134,8 @@ CreateStorageConnection(nsIFile& aDBFile, nsIFile& aFMDirectory,
         }
       }
 
-      connectionOrErr = OpenDatabaseAndHandleBusy(*ss, *dbFileUrl);
+      connectionOrErr =
+          OpenDatabaseAndHandleBusy(*ss, *dbFileUrl, aTelemetryId);
     }
 
     if (NS_WARN_IF(connectionOrErr.isErr())) {
@@ -4547,8 +4549,7 @@ GetStorageConnection(nsIFile& aDatabaseFile, const int64_t aDirectoryLockId,
     return Err(NS_ERROR_DOM_INDEXEDDB_UNKNOWN_ERR);
   }
 
-  auto dbFileUrlOrErr =
-      GetDatabaseFileURL(aDatabaseFile, aDirectoryLockId, aTelemetryId);
+  auto dbFileUrlOrErr = GetDatabaseFileURL(aDatabaseFile, aDirectoryLockId);
   if (NS_WARN_IF(dbFileUrlOrErr.isErr())) {
     return dbFileUrlOrErr.propagateErr();
   }
@@ -4560,7 +4561,7 @@ GetStorageConnection(nsIFile& aDatabaseFile, const int64_t aDirectoryLockId,
   }
 
   auto connectionOrErr =
-      OpenDatabaseAndHandleBusy(*ss, *dbFileUrlOrErr.inspect());
+      OpenDatabaseAndHandleBusy(*ss, *dbFileUrlOrErr.inspect(), aTelemetryId);
   if (NS_WARN_IF(connectionOrErr.isErr())) {
     return connectionOrErr.propagateErr();
   }

diff --git a/storage/mozIStorageService.idl b/storage/mozIStorageService.idl
@@ -161,8 +161,12 @@ interface mozIStorageService : nsISupports {
    *
    * @param aURL
    *        A nsIFileURL that represents the database that is to be opened.
+   * @param [optional] aTelemetryFilename
+   *        The name to use for the database in telemetry. Only needed if the
+   *        actual filename can contain sensitive information.
    */
-  mozIStorageConnection openDatabaseWithFileURL(in nsIFileURL aFileURL);
+  mozIStorageConnection openDatabaseWithFileURL(in nsIFileURL aFileURL,
+                                                [optional] in ACString aTelemetryFilename);
 
   /*
    * Utilities

diff --git a/storage/mozStorageAsyncStatementExecution.cpp b/storage/mozStorageAsyncStatementExecution.cpp
@@ -122,8 +122,10 @@ bool AsyncExecuteStatements::bindExecuteAndProcessStatement(
 
   sqlite3_stmt* aStatement = nullptr;
   // This cannot fail; we are only called if it's available.
-  (void)aData.getSqliteStatement(&aStatement);
-  NS_ASSERTION(aStatement, "You broke the code; do not call here like that!");
+  Unused << aData.getSqliteStatement(&aStatement);
+  MOZ_DIAGNOSTIC_ASSERT(
+      aStatement,
+      "bindExecuteAndProcessStatement called without an initialized statement");
   BindingParamsArray* paramsArray(aData);
 
   // Iterate through all of our parameters, bind them, and execute.
@@ -147,7 +149,7 @@ bool AsyncExecuteStatements::bindExecuteAndProcessStatement(
     // Advance our iterator, execute, and then process the statement.
     itr++;
     bool lastStatement = aLastStatement && itr == end;
-    continueProcessing = executeAndProcessStatement(aStatement, lastStatement);
+    continueProcessing = executeAndProcessStatement(aData, lastStatement);
 
     // Always reset our statement.
     (void)::sqlite3_reset(aStatement);
@@ -156,14 +158,21 @@ bool AsyncExecuteStatements::bindExecuteAndProcessStatement(
   return continueProcessing;
 }
 
-bool AsyncExecuteStatements::executeAndProcessStatement(
-    sqlite3_stmt* aStatement, bool aLastStatement) {
+bool AsyncExecuteStatements::executeAndProcessStatement(StatementData& aData,
+                                                        bool aLastStatement) {
   mMutex.AssertNotCurrentThreadOwns();
 
+  sqlite3_stmt* aStatement = nullptr;
+  // This cannot fail; we are only called if it's available.
+  Unused << aData.getSqliteStatement(&aStatement);
+  MOZ_DIAGNOSTIC_ASSERT(
+      aStatement,
+      "executeAndProcessStatement called without an initialized statement");
+
   // Execute our statement
   bool hasResults;
   do {
-    hasResults = executeStatement(aStatement);
+    hasResults = executeStatement(aData);
 
     // If we had an error, bail.
     if (mState == ERROR || mState == CANCELED) return false;
@@ -208,11 +217,17 @@ bool AsyncExecuteStatements::executeAndProcessStatement(
   return true;
 }
 
-bool AsyncExecuteStatements::executeStatement(sqlite3_stmt* aStatement) {
+bool AsyncExecuteStatements::executeStatement(StatementData& aData) {
   mMutex.AssertNotCurrentThreadOwns();
   Telemetry::AutoTimer<Telemetry::MOZ_STORAGE_ASYNC_REQUESTS_MS>
       finallySendExecutionDuration(mRequestStartDate);
 
+  sqlite3_stmt* aStatement = nullptr;
+  // This cannot fail; we are only called if it's available.
+  Unused << aData.getSqliteStatement(&aStatement);
+  MOZ_DIAGNOSTIC_ASSERT(
+      aStatement, "executeStatement called without an initialized statement");
+
   bool busyRetry = false;
   while (true) {
     if (busyRetry) {
@@ -235,6 +250,16 @@ bool AsyncExecuteStatements::executeStatement(sqlite3_stmt* aStatement) {
     SQLiteMutexAutoLock lockedScope(mDBMutex);
 
     int rc = mConnection->stepStatement(mNativeConnection, aStatement);
+
+    // Some errors are not fatal, and we can handle them and continue.
+    if (rc == SQLITE_BUSY) {
+      ::sqlite3_reset(aStatement);
+      busyRetry = true;
+      continue;
+    }
+
+    aData.MaybeRecordQueryStatus(rc);
+
     // Stop if we have no more results.
     if (rc == SQLITE_DONE) {
       Telemetry::Accumulate(Telemetry::MOZ_STORAGE_ASYNC_REQUESTS_SUCCESS,
@@ -249,13 +274,6 @@ bool AsyncExecuteStatements::executeStatement(sqlite3_stmt* aStatement) {
       return true;
     }
 
-    // Some errors are not fatal, and we can handle them and continue.
-    if (rc == SQLITE_BUSY) {
-      ::sqlite3_reset(aStatement);
-      busyRetry = true;
-      continue;
-    }
-
     if (rc == SQLITE_INTERRUPT) {
       mState = CANCELED;
       return false;
@@ -548,7 +566,7 @@ AsyncExecuteStatements::Run() {
       if (!bindExecuteAndProcessStatement(mStatements[i], finished)) break;
     }
     // Otherwise, just execute and process the statement.
-    else if (!executeAndProcessStatement(stmt, finished)) {
+    else if (!executeAndProcessStatement(mStatements[i], finished)) {
       break;
     }
   }

diff --git a/storage/mozStorageAsyncStatementExecution.h b/storage/mozStorageAsyncStatementExecution.h
@@ -119,26 +119,25 @@ class AsyncExecuteStatements final : public Runnable,
    *
    * @pre mMutex is not held
    *
-   * @param aStatement
-   *        The statement to execute and then process.
+   * @param aData
+   *        The StatementData to execute, and then process.
    * @param aLastStatement
    *        Indicates if this is the last statement or not.  If it is, we have
    *        to set the proper state.
    * @returns true if we should continue to process statements, false otherwise.
    */
-  bool executeAndProcessStatement(sqlite3_stmt* aStatement,
-                                  bool aLastStatement);
+  bool executeAndProcessStatement(StatementData& aData, bool aLastStatement);
 
   /**
    * Executes a statement to completion, properly handling any error conditions.
    *
    * @pre mMutex is not held
    *
-   * @param aStatement
-   *        The statement to execute to completion.
+   * @param aData
+   *        The StatementData to execute to completion.
    * @returns true if results were obtained, false otherwise.
    */
-  bool executeStatement(sqlite3_stmt* aStatement);
+  bool executeStatement(StatementData& aData);
 
   /**
    * Builds a result set up with a row from a given statement.  If we meet the