[UMA] Add performance profile data to UMA uploads.

chrome/browser/metrics/metrics_log.cc

Index: chrome/browser/metrics/metrics_log.cc
diff --git a/chrome/browser/metrics/metrics_log.cc b/chrome/browser/metrics/metrics_log.cc
index 0df2ef1620a8b60832de354ec9b659c89213890a..dd7d99b8cdca9f456ad0d80b11445ccf070d333b 100644
--- a/chrome/browser/metrics/metrics_log.cc
+++ b/chrome/browser/metrics/metrics_log.cc
@@ -17,6 +17,7 @@
 #include "base/sys_info.h"
 #include "base/third_party/nspr/prtime.h"
 #include "base/time.h"
+#include "base/tracked_objects.h"
 #include "base/utf_string_conversions.h"
 #include "chrome/browser/autocomplete/autocomplete.h"
 #include "chrome/browser/autocomplete/autocomplete_match.h"
@@ -27,12 +28,13 @@
 #include "chrome/common/chrome_version_info.h"
 #include "chrome/common/logging_chrome.h"
 #include "chrome/common/metrics/proto/omnibox_event.pb.h"
+#include "chrome/common/metrics/proto/profiler_event.pb.h"
 #include "chrome/common/metrics/proto/system_profile.pb.h"
 #include "chrome/common/pref_names.h"
 #include "content/public/browser/content_browser_client.h"
 #include "content/public/browser/gpu_data_manager.h"
-#include "content/public/common/gpu_info.h"
 #include "content/public/common/content_client.h"
+#include "content/public/common/gpu_info.h"
 #include "googleurl/src/gurl.h"
 #include "ui/gfx/screen.h"
 #include "webkit/plugins/webplugininfo.h"
@@ -46,7 +48,9 @@ extern "C" IMAGE_DOS_HEADER __ImageBase;
 
 using content::GpuDataManager;
 using metrics::OmniboxEventProto;
+using metrics::ProfilerEventProto;
 using metrics::SystemProfileProto;
+using tracked_objects::ProcessDataSnapshot;
 typedef base::FieldTrial::NameGroupId NameGroupId;
 
 namespace {
@@ -141,6 +145,41 @@ OmniboxEventProto::Suggestion::ResultType AsOmniboxEventResultType(
   }
 }
 
+ProfilerEventProto::TrackedObject::ProcessType AsProtobufProcessType(
+    content::ProcessType process_type) {
+  switch (process_type) {
+    case content::PROCESS_TYPE_BROWSER:
+      return ProfilerEventProto::TrackedObject::BROWSER;
+    case content::PROCESS_TYPE_RENDERER:
+      return ProfilerEventProto::TrackedObject::RENDERER;
+    case content::PROCESS_TYPE_PLUGIN:
+      return ProfilerEventProto::TrackedObject::PLUGIN;
+    case content::PROCESS_TYPE_WORKER:
+      return ProfilerEventProto::TrackedObject::WORKER;
+    case content::PROCESS_TYPE_NACL_LOADER:
+      return ProfilerEventProto::TrackedObject::NACL_LOADER;
+    case content::PROCESS_TYPE_UTILITY:
+      return ProfilerEventProto::TrackedObject::UTILITY;
+    case content::PROCESS_TYPE_PROFILE_IMPORT:
+      return ProfilerEventProto::TrackedObject::PROFILE_IMPORT;
+    case content::PROCESS_TYPE_ZYGOTE:
+      return ProfilerEventProto::TrackedObject::ZYGOTE;
+    case content::PROCESS_TYPE_SANDBOX_HELPER:
+      return ProfilerEventProto::TrackedObject::SANDBOX_HELPER;
+    case content::PROCESS_TYPE_NACL_BROKER:
+      return ProfilerEventProto::TrackedObject::NACL_BROKER;
+    case content::PROCESS_TYPE_GPU:
+      return ProfilerEventProto::TrackedObject::GPU;
+    case content::PROCESS_TYPE_PPAPI_PLUGIN:
+      return ProfilerEventProto::TrackedObject::PPAPI_PLUGIN;
+    case content::PROCESS_TYPE_PPAPI_BROKER:
+      return ProfilerEventProto::TrackedObject::PPAPI_BROKER;
+    default:
+      NOTREACHED();
+      return ProfilerEventProto::TrackedObject::UNKNOWN;
+  }
+}
+
 // Returns the plugin preferences corresponding for this user, if available.
 // If multiple user profiles are loaded, returns the preferences corresponding
 // to an arbitrary one of the profiles.
@@ -181,6 +220,44 @@ void WriteFieldTrials(const std::vector<NameGroupId>& field_trial_ids,
   }
 }
 
+void WriteProfilerData(const ProcessDataSnapshot& profiler_data,
+                       content::ProcessType process_type,
+                       ProfilerEventProto* performance_profile) {
+  for (std::vector<tracked_objects::TaskSnapshot>::const_iterator it =
+           profiler_data.tasks.begin();
+       it != profiler_data.tasks.end(); ++it) {
+    std::string ignored;
+    uint64 birth_thread_name_hash;
+    uint64 exec_thread_name_hash;
+    uint64 source_file_name_hash;
+    uint64 source_function_name_hash;
+    MetricsLogBase::CreateHashes(it->birth.thread_name,

[jar (doing other things), 2012/04/19 03:04:56]

We may end up needing to profile this... to see how long it takes... and if it
is too wasteful.
It sure seems like a shame to calculate the SHA hash of the same thread, time
and again.
At a minimum, we should watch for the task that does this protobuf-ication, and
see if it stands out.

[Ilya Sherman, 2012/04/19 21:26:08]

I think the relevant task is "OnProfilerDataCollected", which on my Debug build
does not show up as a hot spot -- the max run time is 12ms (and that includes
loads of about:profiler as well).  Let's definitely keep an eye on it though.

+                                 &ignored, &birth_thread_name_hash);
+    MetricsLogBase::CreateHashes(it->death_thread_name,
+                                 &ignored, &exec_thread_name_hash);
+    MetricsLogBase::CreateHashes(it->birth.location.function_name,
+                                 &ignored, &source_file_name_hash);
+    MetricsLogBase::CreateHashes(it->birth.location.file_name,
+                                 &ignored, &source_function_name_hash);
+
+    const tracked_objects::DeathDataSnapshot& death_data = it->death_data;
+    ProfilerEventProto::TrackedObject* tracked_object =
+        performance_profile->add_tracked_object();
+    tracked_object->set_birth_thread_name_hash(birth_thread_name_hash);
+    tracked_object->set_exec_thread_name_hash(exec_thread_name_hash);
+    tracked_object->set_source_file_name_hash(source_file_name_hash);
+    tracked_object->set_source_function_name_hash(source_function_name_hash);
+    tracked_object->set_source_line_number(it->birth.location.line_number);
+    tracked_object->set_exec_count(death_data.count);
+    tracked_object->set_exec_time_total(death_data.run_duration_sum);
+    tracked_object->set_exec_time_sampled(death_data.run_duration_sample);
+    tracked_object->set_queue_time_total(death_data.queue_duration_sum);
+    tracked_object->set_queue_time_sampled(death_data.queue_duration_sample);
+    tracked_object->set_process_type(AsProtobufProcessType(process_type));
+    tracked_object->set_process_id(profiler_data.process_id);
+  }
+}
+
 }  // namespace
 
 static base::LazyInstance<std::string>::Leaky
@@ -704,6 +781,25 @@ void MetricsLog::RecordEnvironmentProto(
   WriteFieldTrials(field_trial_ids, system_profile);
 }
 
+void MetricsLog::RecordProfilerData(
+    const tracked_objects::ProcessDataSnapshot& process_data,
+    content::ProcessType process_type) {
+  DCHECK(!locked());
+
+  ProfilerEventProto* profile;
+  if (!uma_proto()->profiler_event_size()) {
+    // For the first process's data, add a new field to the protocol buffer.
+    profile = uma_proto()->add_profiler_event();
+    profile->set_profile_type(ProfilerEventProto::STARTUP_PROFILE);
+    profile->set_time_source(ProfilerEventProto::WALL_CLOCK_TIME);

[jar (doing other things), 2012/04/19 03:04:56]

We need to validate this as being the source.  I think we need to augment the
code that changes the time source, so that it sets an inspectable value... which
we can use here to establish the "true" source.
As currently coded, if a person plays with the TCMalloc time source... they'll
corrupt our stats.

[Ilya Sherman, 2012/04/19 21:26:08]

Done.

+  } else {
+    // For the remaining calls, re-use the existing field.
+    profile = uma_proto()->mutable_profiler_event(0);
+  }
+
+  WriteProfilerData(process_data, process_type, profile);
+}
+
 void MetricsLog::WriteAllProfilesMetrics(
     const DictionaryValue& all_profiles_metrics) {
   const std::string profile_prefix(prefs::kProfilePrefix);