IndexedDB: Measure the total database open time.

content/browser/indexed_db/indexed_db_callbacks.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 "content/browser/indexed_db/indexed_db_callbacks.h"
 
 #include <algorithm>
 
 #include "base/guid.h"
+#include "base/metrics/histogram.h"
 #include "base/strings/utf_string_conversions.h"
 #include "base/time/time.h"
 #include "content/browser/child_process_security_policy_impl.h"
 #include "content/browser/fileapi/fileapi_message_filter.h"
 #include "content/browser/indexed_db/indexed_db_blob_info.h"
 #include "content/browser/indexed_db/indexed_db_connection.h"
 #include "content/browser/indexed_db/indexed_db_context_impl.h"
 #include "content/browser/indexed_db/indexed_db_cursor.h"
 #include "content/browser/indexed_db/indexed_db_database_callbacks.h"
 #include "content/browser/indexed_db/indexed_db_database_error.h"
 #include "content/browser/indexed_db/indexed_db_metadata.h"
 #include "content/browser/indexed_db/indexed_db_value.h"
 #include "content/common/indexed_db/indexed_db_constants.h"
 #include "content/common/indexed_db/indexed_db_messages.h"
 #include "webkit/browser/blob/blob_storage_context.h"
 #include "webkit/browser/quota/quota_manager.h"
 #include "webkit/common/blob/blob_data.h"
 #include "webkit/common/blob/shareable_file_reference.h"
 
 using webkit_blob::ShareableFileReference;
 
 namespace content {
 
 namespace {
 const int32 kNoCursor = -1;
 const int32 kNoDatabaseCallbacks = -1;
 const int64 kNoTransaction = -1;
 }
 
+static const char* const kDatabaseOpenTime = "WebCore.IndexedDB.OpenTime";

[Ilya Sherman, 2014/08/14 22:37:49]

nit: I'd include "histogram", and probably also "name", somewhere in the name of
the constant.

[Ilya Sherman, 2014/08/14 22:37:49]

nit: "const char kDatabaseOpenTime[]" is slightly preferred.

+
 IndexedDBCallbacks::IndexedDBCallbacks(IndexedDBDispatcherHost* dispatcher_host,
                                        int32 ipc_thread_id,
                                        int32 ipc_callbacks_id)
     : dispatcher_host_(dispatcher_host),
       ipc_callbacks_id_(ipc_callbacks_id),
       ipc_thread_id_(ipc_thread_id),
       ipc_cursor_id_(kNoCursor),
       host_transaction_id_(kNoTransaction),
       ipc_database_id_(kNoDatabase),
       ipc_database_callbacks_id_(kNoDatabaseCallbacks),
@@ skipping 35 matching lines @@
 }
 
 IndexedDBCallbacks::~IndexedDBCallbacks() {}
 
 void IndexedDBCallbacks::OnError(const IndexedDBDatabaseError& error) {
   DCHECK(dispatcher_host_.get());
 
   dispatcher_host_->Send(new IndexedDBMsg_CallbacksError(
       ipc_thread_id_, ipc_callbacks_id_, error.code(), error.message()));
   dispatcher_host_ = NULL;
+
+  if (!db_open_start_time_.is_null()) {
+    UMA_HISTOGRAM_MEDIUM_TIMES(kDatabaseOpenTime,
+                               base::TimeTicks::Now() - db_open_start_time_);
+    db_open_start_time_ = base::TimeTicks();
+  }
 }
 
 void IndexedDBCallbacks::OnSuccess(const std::vector<base::string16>& value) {
   DCHECK(dispatcher_host_.get());
 
   DCHECK_EQ(kNoCursor, ipc_cursor_id_);
   DCHECK_EQ(kNoTransaction, host_transaction_id_);
   DCHECK_EQ(kNoDatabase, ipc_database_id_);
   DCHECK_EQ(kNoDatabaseCallbacks, ipc_database_callbacks_id_);
   DCHECK_EQ(blink::WebIDBDataLossNone, data_loss_);
@@ skipping 15 matching lines @@
   DCHECK_EQ(kNoTransaction == host_transaction_id_,
             kNoDatabaseCallbacks == ipc_database_callbacks_id_);
   DCHECK_EQ(kNoDatabase, ipc_database_id_);
 
   if (sent_blocked_)
     return;
 
   sent_blocked_ = true;
   dispatcher_host_->Send(new IndexedDBMsg_CallbacksIntBlocked(
       ipc_thread_id_, ipc_callbacks_id_, existing_version));
+
+  if (!db_open_start_time_.is_null()) {
+    UMA_HISTOGRAM_MEDIUM_TIMES(kDatabaseOpenTime,
+                               base::TimeTicks::Now() - db_open_start_time_);
+    db_open_start_time_ = base::TimeTicks();
+  }
 }
 
 void IndexedDBCallbacks::OnDataLoss(blink::WebIDBDataLoss data_loss,
                                     std::string data_loss_message) {
   DCHECK_NE(blink::WebIDBDataLossNone, data_loss);
   data_loss_ = data_loss;
   data_loss_message_ = data_loss_message;
 }
 
 void IndexedDBCallbacks::OnUpgradeNeeded(
@@ skipping 16 matching lines @@
   IndexedDBMsg_CallbacksUpgradeNeeded_Params params;
   params.ipc_thread_id = ipc_thread_id_;
   params.ipc_callbacks_id = ipc_callbacks_id_;
   params.ipc_database_id = ipc_database_id;
   params.ipc_database_callbacks_id = ipc_database_callbacks_id_;
   params.old_version = old_version;
   params.idb_metadata = IndexedDBDispatcherHost::ConvertMetadata(metadata);
   params.data_loss = data_loss_;
   params.data_loss_message = data_loss_message_;
   dispatcher_host_->Send(new IndexedDBMsg_CallbacksUpgradeNeeded(params));
+
+  if (!db_open_start_time_.is_null()) {
+    UMA_HISTOGRAM_MEDIUM_TIMES(kDatabaseOpenTime,
+                               base::TimeTicks::Now() - db_open_start_time_);
+    db_open_start_time_ = base::TimeTicks();
+  }
 }
 
 void IndexedDBCallbacks::OnSuccess(scoped_ptr<IndexedDBConnection> connection,
                                    const IndexedDBDatabaseMetadata& metadata) {
   DCHECK(dispatcher_host_.get());
 
   DCHECK_EQ(kNoCursor, ipc_cursor_id_);
   DCHECK_NE(kNoTransaction, host_transaction_id_);
   DCHECK_NE(ipc_database_id_ == kNoDatabase, !connection);
   DCHECK_NE(kNoDatabaseCallbacks, ipc_database_callbacks_id_);
 
   scoped_refptr<IndexedDBCallbacks> self(this);
 
   int32 ipc_object_id = kNoDatabase;
   // Only register if the connection was not previously sent in OnUpgradeNeeded.
   if (ipc_database_id_ == kNoDatabase) {
     ipc_object_id = dispatcher_host_->Add(
         connection.release(), ipc_thread_id_, origin_url_);
   }
 
   dispatcher_host_->Send(new IndexedDBMsg_CallbacksSuccessIDBDatabase(
       ipc_thread_id_,
       ipc_callbacks_id_,
       ipc_database_callbacks_id_,
       ipc_object_id,
       IndexedDBDispatcherHost::ConvertMetadata(metadata)));
   dispatcher_host_ = NULL;
+
+  if (!db_open_start_time_.is_null()) {
+    UMA_HISTOGRAM_MEDIUM_TIMES(kDatabaseOpenTime,
+                               base::TimeTicks::Now() - db_open_start_time_);
+    db_open_start_time_ = base::TimeTicks();
+  }
 }
 
 static std::string CreateBlobData(
     const IndexedDBBlobInfo& blob_info,
     scoped_refptr<IndexedDBDispatcherHost> dispatcher_host,
     webkit_blob::BlobStorageContext* blob_storage_context,
     base::TaskRunner* task_runner) {
   std::string uuid = blob_info.uuid();
   if (!uuid.empty()) {
     // We're sending back a live blob, not a reference into our backing store.
@@ skipping 370 matching lines @@
   DCHECK_EQ(kNoTransaction, host_transaction_id_);
   DCHECK_EQ(kNoDatabase, ipc_database_id_);
   DCHECK_EQ(kNoDatabaseCallbacks, ipc_database_callbacks_id_);
   DCHECK_EQ(blink::WebIDBDataLossNone, data_loss_);
 
   dispatcher_host_->Send(new IndexedDBMsg_CallbacksSuccessUndefined(
       ipc_thread_id_, ipc_callbacks_id_));
   dispatcher_host_ = NULL;
 }
 
+void IndexedDBCallbacks::SetDatbaseOpenStartTime(

[jsbell, 2014/08/14 22:58:05]

Typo (but at least it compiles!)

+    const base::TimeTicks& start_time) {
+  db_open_start_time_ = start_time;
+}
+
 }  // namespace content