Revert "Revert "Add startup tests that log start script, domcontentloaded, and onload.""

This reverts commit r28209 and relands r28199.

The failure seems to have been flaky (it passed on the other bots and on the following run).  I want to
try to land again.  If it fails again, I'll disable the test.

TBR=mattm

Review URL: http://codereview.chromium.org/268003

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@28268 0039d316-1c4b-4281-b951-d872f2087c98

6 files changed, 99 insertions, 5 deletions

diff --git a/chrome/browser/automation/automation_provider.cc b/chrome/browser/automation/automation_provider.cc
index 38b732e..89a8ec9 100644
--- a/chrome/browser/automation/automation_provider.cc
+++ b/chrome/browser/automation/automation_provider.cc
@@ -133,6 +133,7 @@ AutomationProvider::AutomationProvider(Profile* profile)
       new AutomationAutocompleteEditTracker(this));
   new_tab_ui_load_observer_.reset(new NewTabUILoadObserver(this));
   dom_operation_observer_.reset(new DomOperationNotificationObserver(this));
+  metric_event_duration_observer_.reset(new MetricEventDurationObserver());
 }
 
 AutomationProvider::~AutomationProvider() {
@@ -356,6 +357,8 @@ void AutomationProvider::OnMessageReceived(const IPC::Message& message) {
 #endif
     IPC_MESSAGE_HANDLER(AutomationMsg_GetSecurityState, GetSecurityState)
     IPC_MESSAGE_HANDLER(AutomationMsg_GetPageType, GetPageType)
+    IPC_MESSAGE_HANDLER(AutomationMsg_GetMetricEventDuration,
+                        GetMetricEventDuration)
     IPC_MESSAGE_HANDLER_DELAY_REPLY(AutomationMsg_ActionOnSSLBlockingPage,
                                     ActionOnSSLBlockingPage)
     IPC_MESSAGE_HANDLER(AutomationMsg_BringBrowserToFront, BringBrowserToFront)
@@ -1443,6 +1446,12 @@ void AutomationProvider::GetPageType(int handle, bool* success,
   }
 }
 
+void AutomationProvider::GetMetricEventDuration(const std::string& event_name,
+                                                int* duration_ms) {
+  *duration_ms = metric_event_duration_observer_->GetEventDurationMs(
+      event_name);
+}
+
 void AutomationProvider::ActionOnSSLBlockingPage(int handle, bool proceed,
                                                  IPC::Message* reply_message) {
   if (tab_tracker_->ContainsHandle(handle)) {
diff --git a/chrome/browser/automation/automation_provider.h b/chrome/browser/automation/automation_provider.h
index ef1f228..4ebe00e 100644
--- a/chrome/browser/automation/automation_provider.h
+++ b/chrome/browser/automation/automation_provider.h
@@ -40,10 +40,11 @@ struct Reposition_Params;
 struct ExternalTabSettings;
 }
 
+class ExtensionPortContainer;
+class ExternalTabContainer;
 class LoginHandler;
+class MetricEventDurationObserver;
 class NavigationControllerRestoredObserver;
-class ExternalTabContainer;
-class ExtensionPortContainer;
 struct AutocompleteMatchData;
 
 namespace gfx {
@@ -337,6 +338,10 @@ class AutomationProvider : public base::RefCounted<AutomationProvider>,
   void GetPageType(int handle, bool* success,
                    NavigationEntry::PageType* page_type);
 
+  // Gets the duration in ms of the last event matching |event_name|.
+  // |duration_ms| is -1 if the event hasn't occurred yet.
+  void GetMetricEventDuration(const std::string& event_name, int* duration_ms);
+
   // Simulates an action on the SSL blocking page at the tab specified by
   // |handle|. If |proceed| is true, it is equivalent to the user pressing the
   // 'Proceed' button, if false the 'Get me out of there button'.
@@ -510,6 +515,7 @@ class AutomationProvider : public base::RefCounted<AutomationProvider>,
   scoped_ptr<NotificationObserver> find_in_page_observer_;
   scoped_ptr<NotificationObserver> dom_operation_observer_;
   scoped_ptr<NotificationObserver> dom_inspector_observer_;
+  scoped_ptr<MetricEventDurationObserver> metric_event_duration_observer_;
   scoped_ptr<AutomationBrowserTracker> browser_tracker_;
   scoped_ptr<AutomationTabTracker> tab_tracker_;
   scoped_ptr<AutomationWindowTracker> window_tracker_;
diff --git a/chrome/browser/automation/automation_provider_observers.cc b/chrome/browser/automation/automation_provider_observers.cc
index 57fe3e7..9250ec8 100644
--- a/chrome/browser/automation/automation_provider_observers.cc
+++ b/chrome/browser/automation/automation_provider_observers.cc
@@ -9,13 +9,15 @@
 #include "chrome/browser/automation/automation_provider.h"
 #include "chrome/browser/dom_operation_notification_details.h"
 #include "chrome/browser/login_prompt.h"
-#if defined(OS_WIN)
-#include "chrome/browser/printing/print_job.h"
-#endif  // defined(OS_WIN)
+#include "chrome/browser/metrics/metric_event_duration_details.h"
 #include "chrome/browser/tab_contents/navigation_controller.h"
 #include "chrome/browser/tab_contents/tab_contents.h"
 #include "chrome/common/notification_service.h"
 
+#if defined(OS_WIN)
+#include "chrome/browser/printing/print_job.h"
+#endif  // defined(OS_WIN)
+
 InitialLoadObserver::InitialLoadObserver(size_t tab_count,
                                          AutomationProvider* automation)
     : automation_(automation),
@@ -628,3 +630,28 @@ void DocumentPrintedNotificationObserver::Observe(
   }
 }
 #endif  // defined(OS_WIN)
+
+MetricEventDurationObserver::MetricEventDurationObserver() {
+  registrar_.Add(this, NotificationType::METRIC_EVENT_DURATION,
+                 NotificationService::AllSources());
+}
+
+int MetricEventDurationObserver::GetEventDurationMs(
+    const std::string& event_name) {
+  EventDurationMap::const_iterator it = durations_.find(event_name);
+  if (it == durations_.end())
+    return -1;
+  return it->second;
+}
+
+void MetricEventDurationObserver::Observe(NotificationType type,
+    const NotificationSource& source, const NotificationDetails& details) {
+  if (type != NotificationType::METRIC_EVENT_DURATION) {
+    NOTREACHED();
+    return;
+  }
+  MetricEventDurationDetails* metric_event_duration =
+      Details<MetricEventDurationDetails>(details).ptr();
+  durations_[metric_event_duration->event_name] =
+      metric_event_duration->duration_ms;
+}
diff --git a/chrome/browser/automation/automation_provider_observers.h b/chrome/browser/automation/automation_provider_observers.h
index 2dd596e..5719582 100644
--- a/chrome/browser/automation/automation_provider_observers.h
+++ b/chrome/browser/automation/automation_provider_observers.h
@@ -5,6 +5,7 @@
 #ifndef CHROME_BROWSER_AUTOMATION_AUTOMATION_PROVIDER_OBSERVERS_H_
 #define CHROME_BROWSER_AUTOMATION_AUTOMATION_PROVIDER_OBSERVERS_H_
 
+#include <map>
 #include <set>
 
 #include "chrome/common/notification_observer.h"
@@ -338,4 +339,25 @@ class DocumentPrintedNotificationObserver : public NotificationObserver {
 };
 #endif  // defined(OS_WIN)
 
+// Collects METRIC_EVENT_DURATION notifications and keep track of the times.
+class MetricEventDurationObserver : public NotificationObserver {
+ public:
+  MetricEventDurationObserver();
+
+  // Get the duration of an event.  Returns -1 if we haven't seen the event.
+  int GetEventDurationMs(const std::string& event_name);
+
+  // NotificationObserver interface.
+  virtual void Observe(NotificationType type, const NotificationSource& source,
+                       const NotificationDetails& details);
+
+ private:
+  NotificationRegistrar registrar_;
+
+  typedef std::map<std::string, int> EventDurationMap;
+  EventDurationMap durations_;
+
+  DISALLOW_COPY_AND_ASSIGN(MetricEventDurationObserver);
+};
+
 #endif  // CHROME_BROWSER_AUTOMATION_AUTOMATION_PROVIDER_OBSERVERS_H_
diff --git a/chrome/browser/metrics/metric_event_duration_details.h b/chrome/browser/metrics/metric_event_duration_details.h
new file mode 100644
index 0000000..3e2feec
--- /dev/null
+++ b/chrome/browser/metrics/metric_event_duration_details.h
@@ -0,0 +1,20 @@
+// Copyright (c) 2009 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.
+
+#ifndef CHROME_BROWSER_METRICS_METRIC_EVENT_DURATION_DETAILS_H_
+#define CHROME_BROWSER_METRICS_METRIC_EVENT_DURATION_DETAILS_H_
+
+#include <string>
+
+// Used when sending a notification about an event that occurred that we want
+// to time.
+struct MetricEventDurationDetails {
+  MetricEventDurationDetails(const std::string& e, int d)
+      : event_name(e), duration_ms(d) {}
+
+  std::string event_name;
+  int duration_ms;
+};
+
+#endif  // CHROME_BROWSER_METRICS_METRIC_EVENT_DURATION_DETAILS_H_
diff --git a/chrome/browser/tab_contents/tab_contents.cc b/chrome/browser/tab_contents/tab_contents.cc
index 7735a14..325e6bc 100644
--- a/chrome/browser/tab_contents/tab_contents.cc
+++ b/chrome/browser/tab_contents/tab_contents.cc
@@ -32,6 +32,7 @@
 #include "chrome/browser/jsmessage_box_handler.h"
 #include "chrome/browser/load_from_memory_cache_details.h"
 #include "chrome/browser/load_notification_details.h"
+#include "chrome/browser/metrics/metric_event_duration_details.h"
 #include "chrome/browser/modal_html_dialog_delegate.h"
 #include "chrome/browser/omnibox_search_hint.h"
 #include "chrome/browser/password_manager/password_manager.h"
@@ -1177,6 +1178,9 @@ void TabContents::LogNewTabTime(const std::string& event_name) {
     return;
 
   base::TimeDelta duration = base::TimeTicks::Now() - new_tab_start_time_;
+  MetricEventDurationDetails details(event_name,
+      static_cast<int>(duration.InMilliseconds()));
+
   if (event_name == "NewTab.ScriptStart") {
     UMA_HISTOGRAM_TIMES("NewTab.ScriptStart", duration);
   } else if (event_name == "NewTab.DOMContentLoaded") {
@@ -1185,7 +1189,13 @@ void TabContents::LogNewTabTime(const std::string& event_name) {
     UMA_HISTOGRAM_TIMES("NewTab.Onload", duration);
     // The new tab page has finished loading; reset it.
     new_tab_start_time_ = base::TimeTicks();
+  } else {
+    NOTREACHED();
   }
+  NotificationService::current()->Notify(
+      NotificationType::METRIC_EVENT_DURATION,
+      Source<TabContents>(this),
+      Details<MetricEventDurationDetails>(&details));
 }
 
 // Notifies the RenderWidgetHost instance about the fact that the page is