Collect tab timing information for use in telementry-based startup tests

content/browser/stats_collection_message_filter.cc

Index: content/browser/stats_collection_message_filter.cc
diff --git a/content/browser/stats_collection_message_filter.cc b/content/browser/stats_collection_message_filter.cc
new file mode 100644
index 0000000000000000000000000000000000000000..ec8520ab7ddb5571e2cc479eec06afeb02f69bd0
--- /dev/null
+++ b/content/browser/stats_collection_message_filter.cc
@@ -0,0 +1,200 @@
+// Copyright (c) 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 "content/browser/stats_collection_message_filter.h"
+
+#include <map>
+#include <set>
+
+#include "base/json/json_writer.h"
+#include "base/memory/singleton.h"
+#include "base/process_util.h"
+#include "content/common/child_process_messages.h"
+#include "content/public/browser/notification_registrar.h"
+#include "content/public/browser/notification_service.h"
+#include "content/public/browser/notification_types.h"
+#include "content/public/browser/render_process_host.h"
+
+namespace content {
+
+// Singleton that listens for tab lifetime events (load/unload/crash) and
+// records timing information.
+//
+// Lifetime: Needs to be instantiated before first page load in order to be able
+// to listen to the relevant events.
+// Once instantiated, the class will collect tab timing information for all
+// loded tabs, GetTimingInformation() is used to read out the data.
+class InitialLoadObserver : public content::NotificationObserver {
+ public:
+  static InitialLoadObserver* GetInstance() {
+    return Singleton<InitialLoadObserver>::get();
+  }
+
+  // Overridden from content::NotificationObserver:

[bulach, 2013/03/11 19:11:37]

nit: for consistency with the previous file:
"content::NotificationObserver implementation:"

[jeremy, 2013/03/13 12:07:37]

Done.

+  virtual void Observe(int type,
+                       const content::NotificationSource& source,
+                       const content::NotificationDetails& details) OVERRIDE;
+
+  // Example return value:
+  // {'tabs': [{'start_time_ms': 1, 'stop_time_ms': 2.5},
+  //           {'start_time_ms': 0.5, 'stop_time_ms': 3}]}
+  // stop_time_ms values may be null if a tab hasn't fully loaded.
+  // Only includes entries for the |tab_count| tabs we are monitoring.
+  // There is no defined ordering of the return value.
+  scoped_ptr<base::DictionaryValue> GetTimingInformation() const;
+
+ private:
+  friend struct DefaultSingletonTraits<InitialLoadObserver>;
+
+  class TabTime;
+  typedef std::map<uintptr_t, TabTime> TabTimeMap;
+  typedef std::set<uintptr_t> TabSet;
+
+  InitialLoadObserver();
+  virtual ~InitialLoadObserver();
+
+  content::NotificationRegistrar registrar_;
+  size_t crashed_tab_count_;
+  base::TimeTicks init_time_;
+  TabTimeMap loading_tabs_;
+  TabSet finished_tabs_;
+
+  DISALLOW_COPY_AND_ASSIGN(InitialLoadObserver);
+};
+
+// Holds onto start and stop timestamps for a particular tab.
+class InitialLoadObserver::TabTime {

[bulach, 2013/03/11 19:11:37]

since this is private to a class inside a .cc :) would a struct be sufficient?

[jeremy, 2013/03/13 12:07:37]

Done.

+ public:
+  explicit TabTime(base::TimeTicks started)
+      : load_start_time_(started) {
+  }
+  void set_stop_time(base::TimeTicks stopped) {
+    load_stop_time_ = stopped;
+  }
+  base::TimeTicks stop_time() const {
+    return load_stop_time_;
+  }
+  base::TimeTicks start_time() const {
+    return load_start_time_;
+  }
+ private:
+  base::TimeTicks load_start_time_;
+  base::TimeTicks load_stop_time_;
+};
+
+InitialLoadObserver::InitialLoadObserver()
+    : crashed_tab_count_(0),
+      init_time_(base::TimeTicks::Now()) {
+  registrar_.Add(this, content::NOTIFICATION_LOAD_START,
+                 content::NotificationService::AllSources());
+  registrar_.Add(this, content::NOTIFICATION_LOAD_STOP,
+                 content::NotificationService::AllSources());
+  registrar_.Add(this, content::NOTIFICATION_RENDERER_PROCESS_CLOSED,
+                 content::NotificationService::AllSources());
+}
+
+InitialLoadObserver::~InitialLoadObserver() {
+}
+
+void InitialLoadObserver::Observe(int type,
+                                  const content::NotificationSource& source,
+                                  const content::NotificationDetails& details) {
+  if (type == content::NOTIFICATION_LOAD_START) {
+    loading_tabs_.insert(TabTimeMap::value_type(
+        source.map_key(),
+        TabTime(base::TimeTicks::Now())));
+  } else if (type == content::NOTIFICATION_LOAD_STOP) {
+    TabTimeMap::iterator iter = loading_tabs_.find(source.map_key());
+    if (iter != loading_tabs_.end()) {
+      finished_tabs_.insert(source.map_key());
+      iter->second.set_stop_time(base::TimeTicks::Now());
+    }
+  } else if (type == content::NOTIFICATION_RENDERER_PROCESS_CLOSED) {
+    base::TerminationStatus status =
+        content::Details<content::RenderProcessHost::RendererClosedDetails>(
+            details)->status;
+    switch (status) {
+      case base::TERMINATION_STATUS_NORMAL_TERMINATION:
+        break;
+
+      case base::TERMINATION_STATUS_ABNORMAL_TERMINATION:
+      case base::TERMINATION_STATUS_PROCESS_WAS_KILLED:
+      case base::TERMINATION_STATUS_PROCESS_CRASHED:
+        crashed_tab_count_++;

[bulach, 2013/03/11 19:11:37]

nit: ++crashed_tab_count_;

[jeremy, 2013/03/13 12:07:37]

I prefer keeping it this way if that's ok.

+        break;
+
+      case base::TERMINATION_STATUS_STILL_RUNNING:
+        LOG(ERROR) << "Got RENDERER_PROCESS_CLOSED notification, "
+                   << "but the process is still running. We may miss further "
+                   << "crash notification, resulting in hangs.";
+        break;
+
+      default:
+        LOG(ERROR) << "Unhandled termination status " << status;
+        NOTREACHED();
+        break;
+    }
+  } else {
+    NOTREACHED();
+  }
+}
+
+scoped_ptr<base::DictionaryValue>
+    InitialLoadObserver::GetTimingInformation() const {
+  ListValue* items = new ListValue;
+  for (TabTimeMap::const_iterator it = loading_tabs_.begin();
+       it != loading_tabs_.end();
+       ++it) {
+    DictionaryValue* item = new DictionaryValue;
+    base::TimeDelta delta_start = it->second.start_time() - init_time_;
+
+    item->SetDouble("load_start_ms", delta_start.InMillisecondsF());
+    if (it->second.stop_time().is_null()) {
+      item->Set("load_stop_ms", Value::CreateNullValue());
+    } else {
+      base::TimeDelta delta_stop = it->second.stop_time() - init_time_;
+      item->SetDouble("load_stop_ms", delta_stop.InMillisecondsF());
+    }
+    items->Append(item);
+  }
+  scoped_ptr<DictionaryValue> return_value(new DictionaryValue);
+  return_value->Set("tabs", items);
+  return return_value.Pass();
+}
+
+StatsCollectionMessageFilter::StatsCollectionMessageFilter() {
+  // StatsCollectionMessageFilter's lifetime is tied to a renderer, we want
+  // InitialLoadObserver to stick around and listen for tab loads indefinitely.
+  InitialLoadObserver::GetInstance();
+}
+
+void StatsCollectionMessageFilter::OnChannelConnected(int32 peer_pid) {
+  BrowserMessageFilter::OnChannelConnected(peer_pid);
+}
+
+bool StatsCollectionMessageFilter::OnMessageReceived(
+                                      const IPC::Message& message,

[bulach, 2013/03/11 19:11:37]

nit: indent by +4 from beginning of line

[jeremy, 2013/03/13 12:07:37]

Done.

+                                      bool* message_was_ok) {
+  bool handled = true;
+  IPC_BEGIN_MESSAGE_MAP_EX(StatsCollectionMessageFilter, message,
+                           *message_was_ok)
+    IPC_MESSAGE_HANDLER(ChildProcessHostMsg_GetTabLoadTimingInformation,
+                        OnGetTabLoadTimingInformation)
+    IPC_MESSAGE_UNHANDLED(handled = false)
+  IPC_END_MESSAGE_MAP_EX()
+  return handled;
+}
+
+StatsCollectionMessageFilter::~StatsCollectionMessageFilter() {
+}
+
+void StatsCollectionMessageFilter::OnGetTabLoadTimingInformation(
+    std::string* tab_timing_json) {
+  DCHECK(content::BrowserThread::CurrentlyOn(content::BrowserThread::IO));

[bulach, 2013/03/11 19:11:37]

just checking that the notifications also happen on this thread?

[jeremy, 2013/03/13 12:07:37]

yep

+  scoped_ptr<DictionaryValue> return_value(
+      InitialLoadObserver::GetInstance()->GetTimingInformation());
+  base::JSONWriter::Write(return_value.get(), tab_timing_json);
+}
+
+}  // namespace content