WebSQL: Added database open time statistics reporting.

Source/modules/webdatabase/Database.cpp

 /*
  * Copyright (C) 2013 Apple Inc. All rights reserved.
  *
  * Redistribution and use in source and binary forms, with or without
  * modification, are permitted provided that the following conditions
  * are met:
  * 1. Redistributions of source code must retain the above copyright
  *    notice, this list of conditions and the following disclaimer.
  * 2. Redistributions in binary form must reproduce the above copyright
  *    notice, this list of conditions and the following disclaimer in the
@@ skipping 407 matching lines @@
 
     void setOpenSucceeded() { m_openSucceeded = true; }
 
 private:
     Member<Database> m_database;
     bool m_openSucceeded;
 };
 
 bool Database::performOpenAndVerify(bool shouldSetVersionInNewDatabase, DatabaseError& error, String& errorMessage)
 {
+    double callStartTime = WTF::monotonicallyIncreasingTime();
     DoneCreatingDatabaseOnExitCaller onExitCaller(this);
     ASSERT(errorMessage.isEmpty());
     ASSERT(error == DatabaseError::None); // Better not have any errors already.
     // Presumed failure. We'll clear it if we succeed below.
     error = DatabaseError::InvalidDatabaseState;
 
     const int maxSqliteBusyWaitTime = 30000;
 
     if (!m_sqliteDatabase.open(m_filename)) {
-        reportOpenDatabaseResult(1, InvalidStateError, m_sqliteDatabase.lastError());
+        reportOpenDatabaseResult(1, InvalidStateError, m_sqliteDatabase.lastError(), WTF::monotonicallyIncreasingTime() - callStartTime);
         errorMessage = formatErrorMessage("unable to open database", m_sqliteDatabase.lastError(), m_sqliteDatabase.lastErrorMsg());
         return false;
     }
     if (!m_sqliteDatabase.turnOnIncrementalAutoVacuum())
         WTF_LOG_ERROR("Unable to turn on incremental auto-vacuum (%d %s)", m_sqliteDatabase.lastError(), m_sqliteDatabase.lastErrorMsg());
 
     m_sqliteDatabase.setBusyTimeout(maxSqliteBusyWaitTime);
 
     String currentVersion;
     {
@@ skipping 19 matching lines @@
                 currentVersion = versionFromDatabase;
                 updateGuidVersionMap(m_guid, currentVersion);
             }
             m_sqliteDatabase.setBusyTimeout(maxSqliteBusyWaitTime);
         } else {
             WTF_LOG(StorageAPI, "No cached version for guid %i", m_guid);
 
             SQLiteTransaction transaction(m_sqliteDatabase);
             transaction.begin();
             if (!transaction.inProgress()) {
-                reportOpenDatabaseResult(2, InvalidStateError, m_sqliteDatabase.lastError());
+                reportOpenDatabaseResult(2, InvalidStateError, m_sqliteDatabase.lastError(), WTF::monotonicallyIncreasingTime() - callStartTime);
                 errorMessage = formatErrorMessage("unable to open database, failed to start transaction", m_sqliteDatabase.lastError(), m_sqliteDatabase.lastErrorMsg());
                 m_sqliteDatabase.close();
                 return false;
             }
 
             String tableName(infoTableName);
             if (!m_sqliteDatabase.tableExists(tableName)) {
                 m_new = true;
 
                 if (!m_sqliteDatabase.executeCommand("CREATE TABLE " + tableName + " (key TEXT NOT NULL ON CONFLICT FAIL UNIQUE ON CONFLICT REPLACE,value TEXT NOT NULL ON CONFLICT FAIL);")) {
-                    reportOpenDatabaseResult(3, InvalidStateError, m_sqliteDatabase.lastError());
+                    reportOpenDatabaseResult(3, InvalidStateError, m_sqliteDatabase.lastError(), WTF::monotonicallyIncreasingTime() - callStartTime);
                     errorMessage = formatErrorMessage("unable to open database, failed to create 'info' table", m_sqliteDatabase.lastError(), m_sqliteDatabase.lastErrorMsg());
                     transaction.rollback();
                     m_sqliteDatabase.close();
                     return false;
                 }
             } else if (!getVersionFromDatabase(currentVersion, false)) {
-                reportOpenDatabaseResult(4, InvalidStateError, m_sqliteDatabase.lastError());
+                reportOpenDatabaseResult(4, InvalidStateError, m_sqliteDatabase.lastError(), WTF::monotonicallyIncreasingTime() - callStartTime);
                 errorMessage = formatErrorMessage("unable to open database, failed to read current version", m_sqliteDatabase.lastError(), m_sqliteDatabase.lastErrorMsg());
                 transaction.rollback();
                 m_sqliteDatabase.close();
                 return false;
             }
 
             if (currentVersion.length()) {
                 WTF_LOG(StorageAPI, "Retrieved current version %s from database %s", currentVersion.ascii().data(), databaseDebugName().ascii().data());
             } else if (!m_new || shouldSetVersionInNewDatabase) {
                 WTF_LOG(StorageAPI, "Setting version %s in database %s that was just created", m_expectedVersion.ascii().data(), databaseDebugName().ascii().data());
                 if (!setVersionInDatabase(m_expectedVersion, false)) {
-                    reportOpenDatabaseResult(5, InvalidStateError, m_sqliteDatabase.lastError());
+                    reportOpenDatabaseResult(5, InvalidStateError, m_sqliteDatabase.lastError(), WTF::monotonicallyIncreasingTime() - callStartTime);
                     errorMessage = formatErrorMessage("unable to open database, failed to write current version", m_sqliteDatabase.lastError(), m_sqliteDatabase.lastErrorMsg());
                     transaction.rollback();
                     m_sqliteDatabase.close();
                     return false;
                 }
                 currentVersion = m_expectedVersion;
             }
             updateGuidVersionMap(m_guid, currentVersion);
             transaction.commit();
         }
     }
 
     if (currentVersion.isNull()) {
         WTF_LOG(StorageAPI, "Database %s does not have its version set", databaseDebugName().ascii().data());
         currentVersion = "";
     }
 
     // If the expected version isn't the empty string, ensure that the current
     // database version we have matches that version. Otherwise, set an
     // exception.
     // If the expected version is the empty string, then we always return with
     // whatever version of the database we have.
     if ((!m_new || shouldSetVersionInNewDatabase) && m_expectedVersion.length() && m_expectedVersion != currentVersion) {
-        reportOpenDatabaseResult(6, InvalidStateError, 0);
+        reportOpenDatabaseResult(6, InvalidStateError, 0, WTF::monotonicallyIncreasingTime() - callStartTime);
         errorMessage = "unable to open database, version mismatch, '" + m_expectedVersion + "' does not match the currentVersion of '" + currentVersion + "'";
         m_sqliteDatabase.close();
         return false;
     }
 
     ASSERT(m_databaseAuthorizer);
     m_sqliteDatabase.setAuthorizer(m_databaseAuthorizer.get());
 
     // See comment at the top this file regarding calling addOpenDatabase().
     DatabaseTracker::tracker().addOpenDatabase(this);
     m_opened = true;
 
     // Declare success:
     error = DatabaseError::None; // Clear the presumed error from above.
     onExitCaller.setOpenSucceeded();
 
     if (m_new && !shouldSetVersionInNewDatabase) {
         // The caller provided a creationCallback which will set the expected
         // version.
         m_expectedVersion = "";
     }
 
-    reportOpenDatabaseResult(0, -1, 0); // OK
+    reportOpenDatabaseResult(0, -1, 0, WTF::monotonicallyIncreasingTime() - callStartTime); // OK
 
     if (databaseContext()->databaseThread())
         databaseContext()->databaseThread()->recordDatabaseOpen(this);
     return true;
 }
 
 String Database::stringIdentifier() const
 {
     // Return a deep copy for ref counting thread safety
     return m_name.isolatedCopy();
@@ skipping 143 matching lines @@
     if (totalSize <= 10 * freeSpaceSize) {
         int result = m_sqliteDatabase.runIncrementalVacuumCommand();
         reportVacuumDatabaseResult(result);
         if (result != SQLResultOk)
             logErrorMessage(formatErrorMessage("error vacuuming database", result, m_sqliteDatabase.lastErrorMsg()));
     }
 }
 
 // These are used to generate histograms of errors seen with websql.
 // See about:histograms in chromium.
-void Database::reportOpenDatabaseResult(int errorSite, int webSqlErrorCode, int sqliteErrorCode)
+void Database::reportOpenDatabaseResult(int errorSite, int webSqlErrorCode, int sqliteErrorCode, double duration)
 {
     if (Platform::current()->databaseObserver()) {
         Platform::current()->databaseObserver()->reportOpenDatabaseResult(
             createDatabaseIdentifierFromSecurityOrigin(securityOrigin()),
-            stringIdentifier(), errorSite, webSqlErrorCode, sqliteErrorCode);
+            stringIdentifier(), errorSite, webSqlErrorCode, sqliteErrorCode,
+            duration);
     }
 }
 
 void Database::reportChangeVersionResult(int errorSite, int webSqlErrorCode, int sqliteErrorCode)
 {
     if (Platform::current()->databaseObserver()) {
         Platform::current()->databaseObserver()->reportChangeVersionResult(
             createDatabaseIdentifierFromSecurityOrigin(securityOrigin()),
             stringIdentifier(), errorSite, webSqlErrorCode, sqliteErrorCode);
     }
@@ skipping 169 matching lines @@
 SecurityOrigin* Database::securityOrigin() const
 {
     if (executionContext()->isContextThread())
         return m_contextThreadSecurityOrigin.get();
     if (databaseContext()->databaseThread()->isDatabaseThread())
         return m_databaseThreadSecurityOrigin.get();
     return 0;
 }
 
 } // namespace blink