[Extensions] Add coarse metrics for extension function performance

extensions/browser/extension_function.cc

 // Copyright 2013 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 "extensions/browser/extension_function.h"
 
 #include <utility>
 
 #include "base/logging.h"
 #include "base/macros.h"
 #include "base/memory/ptr_util.h"
 #include "base/memory/singleton.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/synchronization/lock.h"
 #include "content/public/browser/notification_source.h"
 #include "content/public/browser/notification_types.h"
 #include "content/public/browser/render_frame_host.h"
 #include "content/public/browser/web_contents.h"
 #include "content/public/browser/web_contents_observer.h"
 #include "extensions/browser/extension_function_dispatcher.h"
 #include "extensions/browser/extension_message_filter.h"
 #include "extensions/common/error_utils.h"
 #include "extensions/common/extension_api.h"
@@ skipping 376 matching lines @@
   if (bad_message_) {
     type = BAD_MESSAGE;
     LOG(ERROR) << "Bad extension message " << name_;
   }
 
   // If results were never set, we send an empty argument list.
   if (!results_)
     results_.reset(new base::ListValue());
 
   response_callback_.Run(type, *results_, GetError(), histogram_value());
+
+  // TODO(devlin): Once we have a baseline metric for how long functions take,
+  // we can create a handful of buckets and record the function name so that we
+  // can find what the fastest/slowest are. See crbug.com/608561.
+  // Note: Certain functions perform actions that are inherently slow - such as
+  // anything waiting on user action. As such, we can't always assume that a
+  // long execution time equates to a poorly-performing function.
+  if (success) {
+    UMA_HISTOGRAM_TIMES("Extensions.Functions.SucceededTotalExecutionTime",
+                        timer_.Elapsed());
+  } else {
+    UMA_HISTOGRAM_TIMES("Extensions.Functions.FailedTotalExecutionTime",
+                        timer_.Elapsed());
+  }
 }
 
 void ExtensionFunction::OnRespondingLater(ResponseValue value) {
   SendResponse(value->Apply());
 }
 
 UIThreadExtensionFunction::UIThreadExtensionFunction()
     : context_(nullptr),
       render_frame_host_(nullptr),
       delegate_(nullptr) {
@@ skipping 140 matching lines @@
 ExtensionFunction::ResponseAction SyncIOThreadExtensionFunction::Run() {
   return RespondNow(RunSync() ? ArgumentList(std::move(results_))
                               : Error(error_));
 }
 
 // static
 bool SyncIOThreadExtensionFunction::ValidationFailure(
     SyncIOThreadExtensionFunction* function) {
   return false;
 }