Add PipelineStatus UMA logging to media_internals

content/browser/media/media_internals.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/media/media_internals.h"
 
+#include "base/metrics/histogram.h"
 #include "base/strings/string16.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/stringprintf.h"
 #include "content/public/browser/browser_thread.h"
+#include "content/public/browser/notification_service.h"
+#include "content/public/browser/notification_types.h"
+#include "content/public/browser/render_process_host.h"
 #include "content/public/browser/web_ui.h"
 #include "media/audio/audio_parameters.h"
-#include "media/base/media_log.h"
 #include "media/base/media_log_event.h"
 
 namespace {
 
 static base::LazyInstance<content::MediaInternals>::Leaky g_media_internals =
     LAZY_INSTANCE_INITIALIZER;
 
 base::string16 SerializeUpdate(const std::string& function,
                                const base::Value* value) {
   return content::WebUI::GetJavascriptCall(
@@ skipping 143 matching lines @@
                                           base::DictionaryValue* dict) {
   dict->SetInteger("owner_id", owner_id_);
   dict->SetInteger("component_id", component_id);
   dict->SetInteger("component_type", component_);
 }
 
 MediaInternals* MediaInternals::GetInstance() {
   return g_media_internals.Pointer();
 }
 
-MediaInternals::MediaInternals() : owner_ids_() {}
+MediaInternals::MediaInternals() : owner_ids_() {
+  registrar_.Add(this,
+                 NOTIFICATION_RENDERER_PROCESS_TERMINATED,
+                 NotificationService::AllBrowserContextsAndSources());
+}
+
 MediaInternals::~MediaInternals() {}
 
+void MediaInternals::Observe(int type,
+                             const NotificationSource& source,
+                             const NotificationDetails& details) {
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
+  DCHECK_EQ(type, NOTIFICATION_RENDERER_PROCESS_TERMINATED);
+  RenderProcessHost* process = Source<RenderProcessHost>(source).ptr();
+  LogAndClearPlayersInRenderer(process->GetID());
+}
+
+void MediaInternals::LogAndClearPlayersInRenderer(int render_process_id) {
+  auto players_it = renderer_info.find(render_process_id);
+  if (players_it == renderer_info.end())
+    return;
+
+  auto it = players_it->second.begin();
+  while (it != players_it->second.end()) {
+    LogUMAForPipelineStatus(*(it->second));
+    //delete memory allocated for PipelineStatus
+    delete it->second;
+    players_it->second.erase(it++);
+  }
+}
+
 void MediaInternals::OnMediaEvents(
     int render_process_id, const std::vector<media::MediaLogEvent>& events) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   // Notify observers that |event| has occurred.
   for (std::vector<media::MediaLogEvent>::const_iterator event = events.begin();
        event != events.end(); ++event) {
     base::DictionaryValue dict;
     dict.SetInteger("renderer", render_process_id);
     dict.SetInteger("player", event->id);
     dict.SetString("type", media::MediaLog::EventTypeToString(event->type));
 
     // TODO(dalecurtis): This is technically not correct.  TimeTicks "can't" be
     // converted to to a human readable time format.  See base/time/time.h.
     const double ticks = event->time.ToInternalValue();
     const double ticks_millis = ticks / base::Time::kMicrosecondsPerMillisecond;
     dict.SetDouble("ticksMillis", ticks_millis);
     dict.Set("params", event->params.DeepCopy());
     SendUpdate(SerializeUpdate("media.onMediaEvent", &dict));
+    SavePlayerState(*event, render_process_id);
   }
 }
 
+void MediaInternals::SavePlayerState(const media::MediaLogEvent& event,
+                                     int render_process_id) {
+  PlayerInfoMap& player_info = renderer_info[render_process_id];
+  switch (event.type) {
+    case media::MediaLogEvent::WEBMEDIAPLAYER_CREATED: {
+      auto it = player_info.find(event.id);
+      if (it == player_info.end()) {
+        player_info[event.id] = new PipelineInfo();
+      }
+      break;
+    }
+    case media::MediaLogEvent::PIPELINE_ERROR: {
+      std::string status = "";

[DaleCurtis, 2014/11/06 23:49:08]

No need for =""

[prabhur1, 2014/11/07 23:43:23]

Done.

+      event.params.GetString("pipeline_error", &status);
+      media::MediaLog::StringToPipelineStatus(
+          status, player_info[event.id]->last_pipeline_status);
+      break;
+    }
+    case media::MediaLogEvent::PROPERTY_CHANGE:
+      if (event.params.HasKey("found_audio_stream")) {
+        event.params.GetBoolean("found_audio_stream",
+                                &player_info[event.id]->has_audio);
+      }
+      if (event.params.HasKey("found_video_stream")) {
+        event.params.GetBoolean("found_video_stream",
+                                &player_info[event.id]->has_video);
+      }
+      if (event.params.HasKey("audio_codec_name")) {
+        event.params.GetString("audio_codec_name",
+                               &player_info[event.id]->audio_codec_name);
+      }
+      if (event.params.HasKey("video_codec_name")) {
+        event.params.GetString("video_codec_name",
+                               &player_info[event.id]->video_codec_name);
+      }
+      if (event.params.HasKey("video_decoder")) {
+              event.params.GetString("video_decoder",
+                                     &player_info[event.id]->video_decoder);

[prabhur1, 2014/11/06 21:17:51]

Just noticed the formatting. Will fix it in the next iteration.

[prabhur1, 2014/11/07 23:43:23]

Done.

+      }
+      break;
+    default:
+      break;
+  }
+  return;
+}
+
+void MediaInternals::LogUMAForPipelineStatus(const PipelineInfo& player_info) {
+  if (player_info.has_video && player_info.has_audio) {
+    if (player_info.video_codec_name == "vp8") {
+      UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.AudioVideo.VP8",
+                                player_info.last_pipeline_status,
+                                media::PIPELINE_STATUS_MAX + 1);
+    } else if (player_info.video_codec_name == "vp9") {

[prabhur1, 2014/11/06 21:17:51]

This code is not getting hit while playing a vp9 video. It is because
media_internals is not getting the corresponding "video_decode_name" event.
Possibly a bug ?

[DaleCurtis, 2014/11/06 23:49:08]

Yeah sounds like it, can you fix or file a bug?

[prabhur1, 2014/11/07 23:43:23]

Assigned to me : https://code.google.com/p/chromium/issues/detail?id=431443

Done.

+      UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.AudioVideo.VP9",
+                                player_info.last_pipeline_status,
+                                media::PIPELINE_STATUS_MAX + 1);
+    } else if (player_info.video_codec_name == "h264") {
+
+      if (player_info.video_decoder == "gpu") {
+        UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.AudioVideo.HW.H264",
+                                  player_info.last_pipeline_status,
+                                  media::PIPELINE_STATUS_MAX + 1);
+      }
+      else {
+      UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.AudioVideo.SW.H264",
+                                player_info.last_pipeline_status,
+                                media::PIPELINE_STATUS_MAX + 1);
+      }
+    } else {
+      UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.AudioVideo",
+                                player_info.last_pipeline_status,
+                                media::PIPELINE_STATUS_MAX + 1);
+    }
+  } else if (player_info.has_audio) {
+    UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.Audio",
+                              player_info.last_pipeline_status,
+                              media::PIPELINE_STATUS_MAX + 1);
+  } else if (player_info.has_video) {
+    UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.Video",
+                              player_info.last_pipeline_status,
+                              media::PIPELINE_STATUS_MAX + 1);
+  } else {
+    UMA_HISTOGRAM_ENUMERATION("Media.PipelineStatus.Unsupported",

[prabhur1, 2014/11/06 21:17:51]

Youtube videos end up showing as Unsupported because a lot of media_log events
are not received. Could be because those videos use MSE and chunk_demuxer doesnt
currently have any media_log eventing enabled.
Should the chunk demuxer do the same thing as ffmegdemuxer - w.r.t sending
media_log events ?

[DaleCurtis, 2014/11/06 23:49:08]

Hmm, yeah it looks like MSE is sending the raw video codec and audio codec IDs
through error strings. :| Probably we should add some code to MSE to log the
codec_ids as reported to AudioDecoderConfig/VideoDecoderConfig.

[prabhur1, 2014/11/07 23:43:23]

Assigned to me: https://code.google.com/p/chromium/issues/detail?id=431447

[prabhur1, 2014/11/07 23:43:23]

Done.

+                              player_info.last_pipeline_status,
+                              media::PIPELINE_STATUS_MAX + 1);
+  }
+}
+
 void MediaInternals::AddUpdateCallback(const UpdateCallback& callback) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   update_callbacks_.push_back(callback);
 }
 
 void MediaInternals::RemoveUpdateCallback(const UpdateCallback& callback) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
   for (size_t i = 0; i < update_callbacks_.size(); ++i) {
     if (update_callbacks_[i].Equals(callback)) {
       update_callbacks_.erase(update_callbacks_.begin() + i);
@@ skipping 89 matching lines @@
     const std::string& function,
     const base::DictionaryValue* value) {
   SendUpdate(SerializeUpdate(function, value));
 
   base::AutoLock auto_lock(lock_);
   scoped_ptr<base::Value> out_value;
   CHECK(audio_streams_cached_data_.Remove(cache_key, &out_value));
 }
 
 }  // namespace content