Bug 699051. Report slow prepared SQL statements to Telemetry. r=sdwilsh.
authorVladan Djeric <vdjeric@mozilla.com>
Tue, 06 Dec 2011 15:12:55 -0500
changeset 82727 fd47a1e23039fdaa6b818b9967e52ec0e2421248
parent 82726 5d2f9f82004244af1e714b4b2dbeb54131eae7bd
child 82728 42b463638e25bc35997a57e5616a218814f0b9af
push idunknown
push userunknown
push dateunknown
reviewerssdwilsh
bugs699051
milestone11.0a1
Bug 699051. Report slow prepared SQL statements to Telemetry. r=sdwilsh.
storage/src/mozStorageAsyncStatement.cpp
storage/src/mozStorageAsyncStatementExecution.cpp
storage/src/mozStorageConnection.cpp
storage/src/mozStorageConnection.h
storage/src/mozStoragePrivateHelpers.cpp
storage/src/mozStoragePrivateHelpers.h
storage/src/mozStorageStatement.cpp
toolkit/components/telemetry/Telemetry.cpp
toolkit/components/telemetry/Telemetry.h
--- a/storage/src/mozStorageAsyncStatement.cpp
+++ b/storage/src/mozStorageAsyncStatement.cpp
@@ -328,18 +328,17 @@ AsyncStatement::getAsyncStatement(sqlite
   // Make sure we are never called on the connection's owning thread.
   bool onOpenedThread = false;
   (void)mDBConnection->threadOpenedOn->IsOnCurrentThread(&onOpenedThread);
   NS_ASSERTION(!onOpenedThread,
                "We should only be called on the async thread!");
 #endif
 
   if (!mAsyncStatement) {
-    int rc = prepareStmt(mDBConnection->GetNativeConnection(), mSQLString,
-                         &mAsyncStatement);
+    int rc = mDBConnection->prepareStatement(mSQLString, &mAsyncStatement);
     if (rc != SQLITE_OK) {
 #ifdef PR_LOGGING
       PR_LOG(gStorageLog, PR_LOG_ERROR,
              ("Sqlite statement prepare error: %d '%s'", rc,
               ::sqlite3_errmsg(mDBConnection->GetNativeConnection())));
       PR_LOG(gStorageLog, PR_LOG_ERROR,
              ("Statement was: '%s'", mSQLString.get()));
 #endif
--- a/storage/src/mozStorageAsyncStatementExecution.cpp
+++ b/storage/src/mozStorageAsyncStatementExecution.cpp
@@ -360,17 +360,17 @@ bool
 AsyncExecuteStatements::executeStatement(sqlite3_stmt *aStatement)
 {
   mMutex.AssertNotCurrentThreadOwns();
   Telemetry::AutoTimer<Telemetry::MOZ_STORAGE_ASYNC_REQUESTS_MS> finallySendExecutionDuration(mRequestStartDate);
   while (true) {
     // lock the sqlite mutex so sqlite3_errmsg cannot change
     SQLiteMutexAutoLock lockedScope(mDBMutex);
 
-    int rc = stepStmt(aStatement);
+    int rc = mConnection->stepStatement(aStatement);
     // Stop if we have no more results.
     if (rc == SQLITE_DONE)
     {
       Telemetry::Accumulate(Telemetry::MOZ_STORAGE_ASYNC_REQUESTS_SUCCESS, true);
       return false;
     }
 
     // If we got results, we can return now.
--- a/storage/src/mozStorageConnection.cpp
+++ b/storage/src/mozStorageConnection.cpp
@@ -45,16 +45,19 @@
 
 #include "nsError.h"
 #include "nsIMutableArray.h"
 #include "nsHashSets.h"
 #include "nsAutoPtr.h"
 #include "nsIMemoryReporter.h"
 #include "nsThreadUtils.h"
 #include "nsILocalFile.h"
+#include "mozilla/Telemetry.h"
+#include "mozilla/Mutex.h"
+#include "mozilla/CondVar.h"
 
 #include "mozIStorageAggregateFunction.h"
 #include "mozIStorageCompletionCallback.h"
 #include "mozIStorageFunction.h"
 
 #include "mozStorageAsyncStatementExecution.h"
 #include "mozStorageSQLFunctions.h"
 #include "mozStorageConnection.h"
@@ -273,16 +276,76 @@ aggregateFunctionFinalHelper(sqlite3_con
   if (variantToSQLiteT(aCtx, result) != SQLITE_OK) {
     NS_WARNING("User aggregate final function returned invalid data type!");
     ::sqlite3_result_error(aCtx,
                            "User aggregate final function returned invalid data type",
                            -1);
   }
 }
 
+/**
+ * This code is heavily based on the sample at:
+ *   http://www.sqlite.org/unlock_notify.html
+ */
+class UnlockNotification
+{
+public:
+  UnlockNotification()
+  : mMutex("UnlockNotification mMutex")
+  , mCondVar(mMutex, "UnlockNotification condVar")
+  , mSignaled(false)
+  {
+  }
+
+  void Wait()
+  {
+    MutexAutoLock lock(mMutex);
+    while (!mSignaled) {
+      (void)mCondVar.Wait();
+    }
+  }
+
+  void Signal()
+  {
+    MutexAutoLock lock(mMutex);
+    mSignaled = true;
+    (void)mCondVar.Notify();
+  }
+
+private:
+  Mutex mMutex;
+  CondVar mCondVar;
+  bool mSignaled;
+};
+
+void
+UnlockNotifyCallback(void **aArgs,
+                     int aArgsSize)
+{
+  for (int i = 0; i < aArgsSize; i++) {
+    UnlockNotification *notification =
+      static_cast<UnlockNotification *>(aArgs[i]);
+    notification->Signal();
+  }
+}
+
+int
+WaitForUnlockNotify(sqlite3* aDatabase)
+{
+  UnlockNotification notification;
+  int srv = ::sqlite3_unlock_notify(aDatabase, UnlockNotifyCallback,
+                                    &notification);
+  MOZ_ASSERT(srv == SQLITE_LOCKED || srv == SQLITE_OK);
+  if (srv == SQLITE_OK) {
+    notification.Wait();
+  }
+
+  return srv;
+}
+
 } // anonymous namespace
 
 ////////////////////////////////////////////////////////////////////////////////
 //// Local Classes
 
 namespace {
 
 class AsyncCloseConnection : public nsRunnable
@@ -575,19 +638,19 @@ Connection::initialize(nsIFile *aDatabas
   PRInt64 pageSize = DEFAULT_PAGE_SIZE;
   nsCAutoString pageSizeQuery("PRAGMA page_size = ");
   pageSizeQuery.AppendInt(pageSize);
   rv = ExecuteSimpleSQL(pageSizeQuery);
   NS_ENSURE_SUCCESS(rv, rv);
 
   // Get the current page_size, since it may differ from the specified value.
   sqlite3_stmt *stmt;
-  srv = prepareStmt(mDBConn, NS_LITERAL_CSTRING("PRAGMA page_size"), &stmt);
+  srv = prepareStatement(NS_LITERAL_CSTRING("PRAGMA page_size"), &stmt);
   if (srv == SQLITE_OK) {
-    if (SQLITE_ROW == stepStmt(stmt)) {
+    if (SQLITE_ROW == stepStatement(stmt)) {
       pageSize = ::sqlite3_column_int64(stmt, 0);
     }
     (void)::sqlite3_finalize(stmt);
   }
 
   // Setting the cache_size forces the database open, verifying if it is valid
   // or corrupt.  So this is executed regardless it being actually needed.
   // The cache_size is calculated from the actual page_size, to save memory.
@@ -653,21 +716,21 @@ Connection::databaseElementExists(enum D
       query.Append("table");
       break;
   }
   query.Append("' AND name ='");
   query.Append(aElementName);
   query.Append("'");
 
   sqlite3_stmt *stmt;
-  int srv = prepareStmt(mDBConn, query, &stmt);
+  int srv = prepareStatement(query, &stmt);
   if (srv != SQLITE_OK)
     return convertResultCode(srv);
 
-  srv = stepStmt(stmt);
+  srv = stepStatement(stmt);
   // we just care about the return value from step
   (void)::sqlite3_finalize(stmt);
 
   if (srv == SQLITE_ROW) {
     *_exists = true;
     return NS_OK;
   }
   if (srv == SQLITE_DONE) {
@@ -783,16 +846,100 @@ Connection::getFilename()
 {
   nsCString leafname(":memory:");
   if (mDatabaseFile) {
     (void)mDatabaseFile->GetNativeLeafName(leafname);
   }
   return leafname;
 }
 
+int
+Connection::stepStatement(sqlite3_stmt *aStatement)
+{
+  bool checkedMainThread = false;
+  TimeStamp startTime = TimeStamp::Now();
+
+  (void)::sqlite3_extended_result_codes(mDBConn, 1);
+
+  int srv;
+  while ((srv = ::sqlite3_step(aStatement)) == SQLITE_LOCKED_SHAREDCACHE) {
+    if (!checkedMainThread) {
+      checkedMainThread = true;
+      if (::NS_IsMainThread()) {
+        NS_WARNING("We won't allow blocking on the main thread!");
+        break;
+      }
+    }
+
+    srv = WaitForUnlockNotify(mDBConn);
+    if (srv != SQLITE_OK) {
+      break;
+    }
+
+    ::sqlite3_reset(aStatement);
+  }
+
+  // Report very slow SQL statements to Telemetry
+  TimeDuration duration = TimeStamp::Now() - startTime;
+  if (duration.ToMilliseconds() >= Telemetry::kSlowStatementThreshold) {
+    nsDependentCString statementString(::sqlite3_sql(aStatement));
+    Telemetry::RecordSlowSQLStatement(statementString, getFilename(),
+                                      duration.ToMilliseconds());
+  }
+
+  (void)::sqlite3_extended_result_codes(mDBConn, 0);
+  // Drop off the extended result bits of the result code.
+  return srv & 0xFF;
+}
+
+int
+Connection::prepareStatement(const nsCString &aSQL,
+                             sqlite3_stmt **_stmt)
+{
+  bool checkedMainThread = false;
+
+  (void)::sqlite3_extended_result_codes(mDBConn, 1);
+
+  int srv;
+  while((srv = ::sqlite3_prepare_v2(mDBConn, aSQL.get(), -1, _stmt, NULL)) ==
+        SQLITE_LOCKED_SHAREDCACHE) {
+    if (!checkedMainThread) {
+      checkedMainThread = true;
+      if (::NS_IsMainThread()) {
+        NS_WARNING("We won't allow blocking on the main thread!");
+        break;
+      }
+    }
+
+    srv = WaitForUnlockNotify(mDBConn);
+    if (srv != SQLITE_OK) {
+      break;
+    }
+  }
+
+  if (srv != SQLITE_OK) {
+    nsCString warnMsg;
+    warnMsg.AppendLiteral("The SQL statement '");
+    warnMsg.Append(aSQL);
+    warnMsg.AppendLiteral("' could not be compiled due to an error: ");
+    warnMsg.Append(::sqlite3_errmsg(mDBConn));
+
+#ifdef DEBUG
+    NS_WARNING(warnMsg.get());
+#endif
+#ifdef PR_LOGGING
+    PR_LOG(gStorageLog, PR_LOG_ERROR, ("%s", warnMsg.get()));
+#endif
+  }
+
+  (void)::sqlite3_extended_result_codes(mDBConn, 0);
+  // Drop off the extended result bits of the result code.
+  return srv & 0xFF;
+}
+
 ////////////////////////////////////////////////////////////////////////////////
 //// nsIInterfaceRequestor
 
 NS_IMETHODIMP
 Connection::GetInterface(const nsIID &aIID,
                          void **_result)
 {
   if (aIID.Equals(NS_GET_IID(nsIEventTarget))) {
--- a/storage/src/mozStorageConnection.h
+++ b/storage/src/mozStorageConnection.h
@@ -149,16 +149,37 @@ public:
    */
   nsresult internalClose();
 
   /**
    * Obtains the filename of the connection.  Useful for logging.
    */
   nsCString getFilename();
 
+  /**
+   * Creates an sqlite3 prepared statement object from an SQL string.
+   *
+   * @param aSQL
+   *        The SQL statement string to compile.
+   * @param _stmt
+   *        New sqlite3_stmt object.
+   * @return the result from sqlite3_prepare_v2.
+   */
+  int prepareStatement(const nsCString &aSQL, sqlite3_stmt **_stmt);
+
+  /**
+   * Performs a sqlite3_step on aStatement, while properly handling SQLITE_LOCKED
+   * when not on the main thread by waiting until we are notified.
+   *
+   * @param aStatement
+   *        A pointer to a sqlite3_stmt object.
+   * @return the result from sqlite3_step.
+   */
+  int stepStatement(sqlite3_stmt* aStatement);
+
 private:
   ~Connection();
 
   /**
    * Sets the database into a closed state so no further actions can be
    * performed.
    *
    * @note mDBConn is set to NULL in this method.
--- a/storage/src/mozStoragePrivateHelpers.cpp
+++ b/storage/src/mozStoragePrivateHelpers.cpp
@@ -181,17 +181,16 @@ convertJSValToVariant(
     LL_D2L(msec, msecd);
 
     return new IntegerVariant(msec);
   }
 
   return nsnull;
 }
 
-
 namespace {
 class CallbackEvent : public nsRunnable
 {
 public:
   CallbackEvent(mozIStorageCompletionCallback *aCallback)
   : mCallback(aCallback)
   {
   }
@@ -208,148 +207,12 @@ private:
 already_AddRefed<nsIRunnable>
 newCompletionEvent(mozIStorageCompletionCallback *aCallback)
 {
   NS_ASSERTION(aCallback, "Passing a null callback is a no-no!");
   nsCOMPtr<nsIRunnable> event = new CallbackEvent(aCallback);
   return event.forget();
 }
 
-/**
- * This code is heavily based on the sample at:
- *   http://www.sqlite.org/unlock_notify.html
- */
-namespace {
 
-class UnlockNotification
-{
-public:
-  UnlockNotification()
-  : mMutex("UnlockNotification mMutex")
-  , mCondVar(mMutex, "UnlockNotification condVar")
-  , mSignaled(false)
-  {
-  }
-
-  void Wait()
-  {
-    mozilla::MutexAutoLock lock(mMutex);
-    while (!mSignaled) {
-      (void)mCondVar.Wait();
-    }
-  }
-
-  void Signal()
-  {
-    mozilla::MutexAutoLock lock(mMutex);
-    mSignaled = true;
-    (void)mCondVar.Notify();
-  }
-
-private:
-  mozilla::Mutex mMutex;
-  mozilla::CondVar mCondVar;
-  bool mSignaled;
-};
-
-void
-UnlockNotifyCallback(void **aArgs,
-                     int aArgsSize)
-{
-  for (int i = 0; i < aArgsSize; i++) {
-    UnlockNotification *notification =
-      static_cast<UnlockNotification *>(aArgs[i]);
-    notification->Signal();
-  }
-}
-
-int
-WaitForUnlockNotify(sqlite3* aDatabase)
-{
-  UnlockNotification notification;
-  int srv = ::sqlite3_unlock_notify(aDatabase, UnlockNotifyCallback,
-                                    &notification);
-  NS_ASSERTION(srv == SQLITE_LOCKED || srv == SQLITE_OK, "Bad result!");
-  if (srv == SQLITE_OK)
-    notification.Wait();
-
-  return srv;
-}
-
-} // anonymous namespace
-
-int
-stepStmt(sqlite3_stmt* aStatement)
-{
-  bool checkedMainThread = false;
-
-  sqlite3* db = ::sqlite3_db_handle(aStatement);
-  (void)::sqlite3_extended_result_codes(db, 1);
-
-  int srv;
-  while ((srv = ::sqlite3_step(aStatement)) == SQLITE_LOCKED_SHAREDCACHE) {
-    if (!checkedMainThread) {
-      checkedMainThread = true;
-      if (NS_IsMainThread()) {
-        NS_WARNING("We won't allow blocking on the main thread!");
-        break;
-      }
-    }
-
-    srv = WaitForUnlockNotify(sqlite3_db_handle(aStatement));
-    if (srv != SQLITE_OK)
-      break;
-
-    ::sqlite3_reset(aStatement);
-  }
-
-  (void)::sqlite3_extended_result_codes(db, 0);
-  // Drop off the extended result bits of the result code.
-  return srv & 0xFF;
-}
-
-int
-prepareStmt(sqlite3* aDatabase,
-            const nsCString &aSQL,
-            sqlite3_stmt **_stmt)
-{
-  bool checkedMainThread = false;
-
-  (void)::sqlite3_extended_result_codes(aDatabase, 1);
-
-  int srv;
-  while((srv = ::sqlite3_prepare_v2(aDatabase, aSQL.get(), -1, _stmt, NULL)) ==
-        SQLITE_LOCKED_SHAREDCACHE) {
-    if (!checkedMainThread) {
-      checkedMainThread = true;
-      if (NS_IsMainThread()) {
-        NS_WARNING("We won't allow blocking on the main thread!");
-        break;
-      }
-    }
-
-    srv = WaitForUnlockNotify(aDatabase);
-    if (srv != SQLITE_OK)
-      break;
-  }
-
-  if (srv != SQLITE_OK) {
-    nsCString warnMsg;
-    warnMsg.AppendLiteral("The SQL statement '");
-    warnMsg.Append(aSQL);
-    warnMsg.AppendLiteral("' could not be compiled due to an error: ");
-    warnMsg.Append(::sqlite3_errmsg(aDatabase));
-
-#ifdef DEBUG
-    NS_WARNING(warnMsg.get());
-#endif
-#ifdef PR_LOGGING
-    PR_LOG(gStorageLog, PR_LOG_ERROR, ("%s", warnMsg.get()));
-#endif
-  }
-
-  (void)::sqlite3_extended_result_codes(aDatabase, 0);
-  // Drop off the extended result bits of the result code.
-  return srv & 0xFF;
-}
 
 } // namespace storage
 } // namespace mozilla
--- a/storage/src/mozStoragePrivateHelpers.h
+++ b/storage/src/mozStoragePrivateHelpers.h
@@ -108,35 +108,12 @@ nsIVariant *convertJSValToVariant(JSCont
  * @param aCallback
  *        The callback to be notified.
  * @return an nsIRunnable that can be dispatched to the calling thread.
  */
 already_AddRefed<nsIRunnable> newCompletionEvent(
   mozIStorageCompletionCallback *aCallback
 );
 
-
-/**
- * Performs a sqlite3_step on aStatement, while properly handling SQLITE_LOCKED
- * when not on the main thread by waiting until we are notified.
- *
- * @param aStatement
- *        A pointer to a sqlite3_stmt object.
- * @return the result from sqlite3_step.
- */
-int stepStmt(sqlite3_stmt *aStatement);
-
-/**
- * Obtains a prepared sqlite3_stmt object for aDatabase from aSQL.
- *
- * @param aDatabase
- *        The database the statement will execute on.
- * @param aSQL
- *        The SQL statement to compile.
- * @return the result from sqlite3_prepare_v2.
- */
-int prepareStmt(sqlite3 *aDatabase, const nsCString &aSQL,
-                sqlite3_stmt **_stmt);
-
 } // namespace storage
 } // namespace mozilla
 
 #endif // mozStoragePrivateHelpers_h
--- a/storage/src/mozStorageStatement.cpp
+++ b/storage/src/mozStorageStatement.cpp
@@ -170,17 +170,18 @@ Statement::initialize(Connection *aDBCon
                       const nsACString &aSQLStatement)
 {
   NS_ASSERTION(aDBConnection, "No database connection given!");
   NS_ASSERTION(!mDBStatement, "Statement already initialized!");
 
   sqlite3 *db = aDBConnection->GetNativeConnection();
   NS_ASSERTION(db, "We should never be called with a null sqlite3 database!");
 
-  int srv = prepareStmt(db, PromiseFlatCString(aSQLStatement), &mDBStatement);
+  int srv = aDBConnection->prepareStatement(PromiseFlatCString(aSQLStatement),
+                                            &mDBStatement);
   if (srv != SQLITE_OK) {
 #ifdef PR_LOGGING
       PR_LOG(gStorageLog, PR_LOG_ERROR,
              ("Sqlite statement prepare error: %d '%s'", srv,
               ::sqlite3_errmsg(db)));
       PR_LOG(gStorageLog, PR_LOG_ERROR,
              ("Statement was: '%s'", PromiseFlatCString(aSQLStatement).get()));
 #endif
@@ -314,18 +315,17 @@ int
 Statement::getAsyncStatement(sqlite3_stmt **_stmt)
 {
   // If we have no statement, we shouldn't be calling this method!
   NS_ASSERTION(mDBStatement != NULL, "We have no statement to clone!");
 
   // If we do not yet have a cached async statement, clone our statement now.
   if (!mAsyncStatement) {
     nsDependentCString sql(::sqlite3_sql(mDBStatement));
-    int rc = prepareStmt(mDBConnection->GetNativeConnection(), sql,
-                     &mAsyncStatement);
+    int rc = mDBConnection->prepareStatement(sql, &mAsyncStatement);
     if (rc != SQLITE_OK) {
       *_stmt = nsnull;
       return rc;
     }
 
 #ifdef PR_LOGGING
     PR_LOG(gStorageLog, PR_LOG_NOTICE,
            ("Cloned statement 0x%p to 0x%p", mDBStatement, mAsyncStatement));
@@ -608,17 +608,17 @@ Statement::ExecuteStep(bool *_moreResult
       PRInt32 srv;
       (void)error->GetResult(&srv);
       return convertResultCode(srv);
     }
 
     // We have bound, so now we can clear our array.
     mParamsArray = nsnull;
   }
-  int srv = stepStmt(mDBStatement);
+  int srv = mDBConnection->stepStatement(mDBStatement);
 
 #ifdef PR_LOGGING
   if (srv != SQLITE_ROW && srv != SQLITE_DONE) {
       nsCAutoString errStr;
       (void)mDBConnection->GetLastErrorString(errStr);
       PR_LOG(gStorageLog, PR_LOG_DEBUG,
              ("Statement::ExecuteStep error: %s", errStr.get()));
   }
--- a/toolkit/components/telemetry/Telemetry.cpp
+++ b/toolkit/components/telemetry/Telemetry.cpp
@@ -46,16 +46,18 @@
 #include "jsapi.h" 
 #include "nsStringGlue.h"
 #include "nsITelemetry.h"
 #include "Telemetry.h" 
 #include "nsTHashtable.h"
 #include "nsHashKeys.h"
 #include "nsBaseHashtable.h"
 #include "nsXULAppAPI.h"
+#include "nsThreadUtils.h"
+#include "mozilla/Mutex.h"
 
 namespace {
 
 using namespace base;
 using namespace mozilla;
 
 class TelemetryImpl : public nsITelemetry
 {
@@ -64,24 +66,38 @@ class TelemetryImpl : public nsITelemetr
 
 public:
   TelemetryImpl();
   ~TelemetryImpl();
   
   static bool CanRecord();
   static already_AddRefed<nsITelemetry> CreateTelemetryInstance();
   static void ShutdownTelemetry();
+  static void RecordSlowStatement(const nsACString &statement,
+                                  const nsACString &dbName,
+                                  PRUint32 delay);
+  struct StmtStats {
+    PRUint32 hitCount;
+    PRUint32 totalTime;
+  };
+  typedef nsBaseHashtableET<nsCStringHashKey, StmtStats> SlowSQLEntryType;
 
 private:
+  bool AddSlowSQLInfo(JSContext *cx, JSObject *rootObj, bool mainThread);
+
   // This is used for speedy JS string->Telemetry::ID conversions
   typedef nsBaseHashtableET<nsCharPtrHashKey, Telemetry::ID> CharPtrEntryType;
   typedef nsTHashtable<CharPtrEntryType> HistogramMapType;
   HistogramMapType mHistogramMap;
   bool mCanRecord;
   static TelemetryImpl *sTelemetry;
+  nsTHashtable<SlowSQLEntryType> mSlowSQLOnMainThread;
+  nsTHashtable<SlowSQLEntryType> mSlowSQLOnOtherThread;
+  nsTHashtable<nsCStringHashKey> mTrackedDBs;
+  Mutex mHashMutex;
 };
 
 TelemetryImpl*  TelemetryImpl::sTelemetry = NULL;
 
 // A initializer to initialize histogram collection
 StatisticsRecorder gStatisticsRecorder;
 
 // Hardcoded probes
@@ -262,36 +278,133 @@ WrapAndReturnHistogram(Histogram *h, JSC
     return NS_ERROR_FAILURE;
   *ret = OBJECT_TO_JSVAL(obj);
   return (JS_SetPrivate(cx, obj, h)
           && JS_DefineFunction (cx, obj, "add", JSHistogram_Add, 1, 0)
           && JS_DefineFunction (cx, obj, "snapshot", JSHistogram_Snapshot, 1, 0)) ? NS_OK : NS_ERROR_FAILURE;
 }
 
 TelemetryImpl::TelemetryImpl():
-mCanRecord(XRE_GetProcessType() == GeckoProcessType_Default)
+mCanRecord(XRE_GetProcessType() == GeckoProcessType_Default),
+mHashMutex("Telemetry::mHashMutex")
 {
+  // A whitelist to prevent Telemetry reporting on Addon & Thunderbird DBs
+  const char *trackedDBs[] = {
+    "addons.sqlite", "chromeappsstore.sqlite", "content-prefs.sqlite",
+    "cookies.sqlite", "downloads.sqlite", "extensions.sqlite",
+    "formhistory.sqlite", "index.sqlite", "permissions.sqlite", "places.sqlite",
+    "search.sqlite", "signons.sqlite", "urlclassifier3.sqlite",
+    "webappsstore.sqlite"
+  };
+
+  mTrackedDBs.Init();
+  for (int i = 0; i < sizeof(trackedDBs)/sizeof(const char*); i++)
+    mTrackedDBs.PutEntry(nsDependentCString(trackedDBs[i]));
+
+  mSlowSQLOnMainThread.Init();
+  mSlowSQLOnOtherThread.Init();
   mHistogramMap.Init(Telemetry::HistogramCount);
 }
 
 TelemetryImpl::~TelemetryImpl() {
+  mTrackedDBs.Clear();
+  mSlowSQLOnMainThread.Clear();
+  mSlowSQLOnOtherThread.Clear();
   mHistogramMap.Clear();
 }
 
 NS_IMETHODIMP
 TelemetryImpl::NewHistogram(const nsACString &name, PRUint32 min, PRUint32 max, PRUint32 bucketCount, PRUint32 histogramType, JSContext *cx, jsval *ret)
 {
   Histogram *h;
   nsresult rv = HistogramGet(PromiseFlatCString(name).get(), min, max, bucketCount, histogramType, &h);
   if (NS_FAILED(rv))
     return rv;
   h->ClearFlags(Histogram::kUmaTargetedHistogramFlag);
   return WrapAndReturnHistogram(h, cx, ret);
 }
 
+struct EnumeratorArgs {
+  JSContext *cx;
+  JSObject *statsObj;
+  JSObject *statementsObj;
+  int32 statementIndex;
+};
+
+PLDHashOperator
+StatementEnumerator(TelemetryImpl::SlowSQLEntryType *entry, void *arg)
+{
+  EnumeratorArgs *args = static_cast<EnumeratorArgs *>(arg);
+  const nsACString &statement = entry->GetKey();
+  jsval hitCount = UINT_TO_JSVAL(entry->mData.hitCount);
+  jsval totalTime = UINT_TO_JSVAL(entry->mData.totalTime);
+  args->statementIndex++;
+
+  JSObject *hitsAndTimeObj = JS_NewArrayObject(args->cx, 2, nsnull);
+  if (!hitsAndTimeObj ||
+      !JS_SetElement(args->cx, hitsAndTimeObj, 0, &hitCount) ||
+      !JS_SetElement(args->cx, hitsAndTimeObj, 1, &totalTime))
+    return PL_DHASH_STOP;
+
+  jsid propertyId = INT_TO_JSID(args->statementIndex);
+  JSBool success = JS_DefinePropertyById(args->cx, args->statsObj,
+                                         INT_TO_JSID(args->statementIndex),
+                                         OBJECT_TO_JSVAL(hitsAndTimeObj),
+                                         NULL, NULL, JSPROP_ENUMERATE);
+  if (!success)
+    return PL_DHASH_STOP;
+
+  JSString *string = JS_NewStringCopyN(args->cx, statement.BeginReading(), statement.Length());
+  if (!string)
+    return PL_DHASH_STOP;
+
+  success = JS_DefinePropertyById(args->cx, args->statementsObj,
+                                  INT_TO_JSID(args->statementIndex),
+                                  STRING_TO_JSVAL(string), NULL, NULL,
+                                  JSPROP_ENUMERATE);
+  if (!success)
+    return PL_DHASH_STOP;
+
+  return PL_DHASH_NEXT;
+}
+
+bool
+TelemetryImpl::AddSlowSQLInfo(JSContext *cx, JSObject *rootObj, bool mainThread)
+{
+  JSObject *statementsObj = JS_NewObject(cx, NULL, NULL, NULL);
+  JSObject *statsObj = JS_NewObject(cx, NULL, NULL, NULL);
+  if (!statementsObj || !statsObj)
+    return false;
+
+  JSBool ok = JS_DefineProperty(cx, rootObj,
+                                mainThread ? "slowSQLOnMain" : "slowSQLOnOther",
+                                OBJECT_TO_JSVAL(statementsObj),
+                                NULL, NULL, JSPROP_ENUMERATE);
+  if (!ok)
+    return false;
+
+  ok = JS_DefineProperty(cx, rootObj,
+                         mainThread ? "slowSQLStatsMain" : "slowSQLStatsOther",
+                         OBJECT_TO_JSVAL(statsObj),
+                         NULL, NULL, JSPROP_ENUMERATE);
+  if (!ok)
+    return false;
+
+  EnumeratorArgs args = { cx, statsObj, statementsObj, 0 };
+  nsTHashtable<SlowSQLEntryType> *sqlMap;
+  sqlMap = (mainThread ? &mSlowSQLOnMainThread : &mSlowSQLOnOtherThread);
+  PRUint32 num = sqlMap->EnumerateEntries(StatementEnumerator,
+                                          static_cast<void*>(&args));
+  if (num != sqlMap->Count())
+    return false;
+
+  return true;
+}
+
+
 NS_IMETHODIMP
 TelemetryImpl::GetHistogramSnapshots(JSContext *cx, jsval *ret)
 {
   JSObject *root_obj = JS_NewObject(cx, NULL, NULL, NULL);
   if (!root_obj)
     return NS_ERROR_FAILURE;
   *ret = OBJECT_TO_JSVAL(root_obj);
 
@@ -302,20 +415,28 @@ TelemetryImpl::GetHistogramSnapshots(JSC
     JSObject *hobj = JS_NewObject(cx, NULL, NULL, NULL);
     if (!(hobj
           && JS_DefineProperty(cx, root_obj, h->histogram_name().c_str(),
                                OBJECT_TO_JSVAL(hobj), NULL, NULL, JSPROP_ENUMERATE)
           && ReflectHistogramSnapshot(cx, hobj, h))) {
       return NS_ERROR_FAILURE;
     }
   }
+
+  MutexAutoLock hashMutex(mHashMutex);
+  // Add info about slow SQL queries on the main thread
+  if (!AddSlowSQLInfo(cx, root_obj, true))
+    return NS_ERROR_FAILURE;
+  // Add info about slow SQL queries on other threads
+  if (!AddSlowSQLInfo(cx, root_obj, false))
+    return NS_ERROR_FAILURE;
+
   return NS_OK;
 }
 
-
 NS_IMETHODIMP
 TelemetryImpl::GetHistogramById(const nsACString &name, JSContext *cx, jsval *ret)
 {
   // Cache names
   // Note the histogram names are statically allocated
   if (!mHistogramMap.Count()) {
     for (PRUint32 i = 0; i < Telemetry::HistogramCount; i++) {
       CharPtrEntryType *entry = mHistogramMap.PutEntry(gHistograms[i].id);
@@ -370,16 +491,51 @@ TelemetryImpl::CreateTelemetryInstance()
 }
 
 void
 TelemetryImpl::ShutdownTelemetry()
 {
   NS_IF_RELEASE(sTelemetry);
 }
 
+void
+TelemetryImpl::RecordSlowStatement(const nsACString &statement,
+                                   const nsACString &dbName,
+                                   PRUint32 delay)
+{
+  if (!sTelemetry) {
+    // Make the service manager hold a long-lived reference to the service
+    nsCOMPtr<nsITelemetry> telemetryService =
+      do_GetService("@mozilla.org/base/telemetry;1");
+    if (!telemetryService || !sTelemetry)
+      return;
+  }
+
+  if (!sTelemetry->mCanRecord || !sTelemetry->mTrackedDBs.GetEntry(dbName))
+    return;
+
+  nsTHashtable<SlowSQLEntryType> *slowSQLMap = NULL;
+  if (NS_IsMainThread())
+    slowSQLMap = &(sTelemetry->mSlowSQLOnMainThread);
+  else
+    slowSQLMap = &(sTelemetry->mSlowSQLOnOtherThread);
+
+  MutexAutoLock hashMutex(sTelemetry->mHashMutex);
+  SlowSQLEntryType *entry = slowSQLMap->GetEntry(statement);
+  if (!entry) {
+    entry = slowSQLMap->PutEntry(statement);
+    if (NS_UNLIKELY(!entry))
+      return;
+    entry->mData.hitCount = 0;
+    entry->mData.totalTime = 0;
+  }
+  entry->mData.hitCount++;
+  entry->mData.totalTime += delay;
+}
+
 NS_IMPL_THREADSAFE_ISUPPORTS1(TelemetryImpl, nsITelemetry)
 NS_GENERIC_FACTORY_SINGLETON_CONSTRUCTOR(nsITelemetry, TelemetryImpl::CreateTelemetryInstance)
 
 #define NS_TELEMETRY_CID \
   {0xaea477f2, 0xb3a2, 0x469c, {0xaa, 0x29, 0x0a, 0x82, 0xd1, 0x32, 0xb8, 0x29}}
 NS_DEFINE_NAMED_CID(NS_TELEMETRY_CID);
 
 const Module::CIDEntry kTelemetryCIDs[] = {
@@ -429,16 +585,24 @@ AccumulateTimeDelta(ID aHistogram, TimeS
 base::Histogram*
 GetHistogramById(ID id)
 {
   Histogram *h = NULL;
   GetHistogramByEnumId(id, &h);
   return h;
 }
 
+void
+RecordSlowSQLStatement(const nsACString &statement,
+                       const nsACString &dbName,
+                       PRUint32 delay)
+{
+  TelemetryImpl::RecordSlowStatement(statement, dbName, delay);
+}
+
 } // namespace Telemetry
 } // namespace mozilla
 
 NSMODULE_DEFN(nsTelemetryModule) = &kTelemetryModule;
 
 /**
  * The XRE_TelemetryAdd function is to be used by embedding applications
  * that can't use mozilla::Telemetry::Accumulate() directly.
--- a/toolkit/components/telemetry/Telemetry.h
+++ b/toolkit/components/telemetry/Telemetry.h
@@ -93,11 +93,29 @@ public:
   ~AutoTimer() {
     AccumulateTimeDelta(id, start);
   }
 
 private:
   const TimeStamp start;
   MOZILLA_DECL_USE_GUARD_OBJECT_NOTIFIER
 };
+
+/**
+ * Records slow SQL statements for Telemetry reporting.
+ * For privacy reasons, only prepared statements are reported.
+ *
+ * @param statement - offending SQL statement to record
+ * @param dbName - DB filename; reporting is only done for whitelisted DBs
+ * @param delay - execution time in milliseconds
+ */
+void RecordSlowSQLStatement(const nsACString &statement,
+                            const nsACString &dbName,
+                            PRUint32 delay);
+
+/**
+ * Threshold for a statement to be considered slow, in milliseconds
+ */
+const PRUint32 kSlowStatementThreshold = 100;
+
 } // namespace Telemetry
 } // namespace mozilla
 #endif // Telemetry_h__