media: Add UMA and trace events for CDM creation.

media/blink/cdm_session_adapter.cc

Index: media/blink/cdm_session_adapter.cc
diff --git a/media/blink/cdm_session_adapter.cc b/media/blink/cdm_session_adapter.cc
index 46147694d0d0eb0421cb9bb187b2c489c676c7dd..099f18b0268f16e02befc06d4bbf97434067ff4c 100644
--- a/media/blink/cdm_session_adapter.cc
+++ b/media/blink/cdm_session_adapter.cc
@@ -6,7 +6,9 @@
 
 #include "base/bind.h"
 #include "base/logging.h"
+#include "base/metrics/histogram.h"
 #include "base/stl_util.h"
+#include "base/trace_event/trace_event.h"
 #include "media/base/cdm_factory.h"
 #include "media/base/cdm_key_information.h"
 #include "media/base/cdm_promise.h"
@@ -19,9 +21,10 @@ namespace media {
 
 const char kMediaEME[] = "Media.EME.";
 const char kDot[] = ".";
+const char kCdmCreationTimeUMAName[] = "CreateCdm";

[ddorwin, 2015/07/20 21:35:21]

nit: CreateCdm seems very implementation-specific. What does it mean to "create
a CDM?" CdmCreationTime? Really it's the CdmInstantiationTime, but that's wordy.

Does "time" usually mean "duration" in UMAs?

[xhwang, 2015/07/20 22:11:56]

As discussed offline, we'll use "CreateCdmTime" in UMA name and
"TimeToCreateCdm" in code.

 
-CdmSessionAdapter::CdmSessionAdapter() : weak_ptr_factory_(this) {
-}
+CdmSessionAdapter::CdmSessionAdapter()
+    : trace_id_(0), weak_ptr_factory_(this) {}
 
 CdmSessionAdapter::~CdmSessionAdapter() {}
 
@@ -31,6 +34,11 @@ void CdmSessionAdapter::CreateCdm(
     const GURL& security_origin,
     const CdmConfig& cdm_config,
     blink::WebContentDecryptionModuleResult result) {
+  TRACE_EVENT_ASYNC_BEGIN0("media", "CdmSessionAdapter::CreateCdm",
+                           ++trace_id_);
+
+  base::TimeTicks start_time = base::TimeTicks::Now();
+
   // Note: WebContentDecryptionModuleImpl::Create() calls this method without
   // holding a reference to the CdmSessionAdapter. Bind OnCdmCreated() with
   // |this| instead of |weak_this| to prevent |this| from being destructed.
@@ -42,7 +50,8 @@ void CdmSessionAdapter::CreateCdm(
       base::Bind(&CdmSessionAdapter::OnLegacySessionError, weak_this),
       base::Bind(&CdmSessionAdapter::OnSessionKeysChange, weak_this),
       base::Bind(&CdmSessionAdapter::OnSessionExpirationUpdate, weak_this),
-      base::Bind(&CdmSessionAdapter::OnCdmCreated, this, key_system, result));
+      base::Bind(&CdmSessionAdapter::OnCdmCreated, this, key_system, start_time,
+                 result));
 }
 
 void CdmSessionAdapter::SetServerCertificate(
@@ -111,15 +120,23 @@ const std::string& CdmSessionAdapter::GetKeySystem() const {
 }
 
 const std::string& CdmSessionAdapter::GetKeySystemUMAPrefix() const {
+  DCHECK(!key_system_uma_prefix_.empty());
   return key_system_uma_prefix_;
 }
 
 void CdmSessionAdapter::OnCdmCreated(
     const std::string& key_system,
+    base::TimeTicks start_time,
     blink::WebContentDecryptionModuleResult result,
     scoped_ptr<MediaKeys> cdm,
     const std::string& error_message) {
   DVLOG(2) << __FUNCTION__;
+  DCHECK(!cdm_);
+
+  TRACE_EVENT_ASYNC_END2("media", "CdmSessionAdapter::CreateCdm", trace_id_,
+                         "success", (cdm ? "true" : "false"), "error_message",
+                         error_message);
+
   if (!cdm) {
     result.completeWithError(
         blink::WebContentDecryptionModuleExceptionNotSupportedError, 0,
@@ -130,6 +147,10 @@ void CdmSessionAdapter::OnCdmCreated(
   key_system_ = key_system;
   key_system_uma_prefix_ =
       kMediaEME + GetKeySystemNameForUMA(key_system) + kDot;
+
+  // Only report time for successful CDM creation.
+  ReportCdmCreationTimeUMA(base::TimeTicks::Now() - start_time);
+
   cdm_ = cdm.Pass();
 
   result.completeWithContentDecryptionModule(
@@ -195,4 +216,15 @@ WebContentDecryptionModuleSessionImpl* CdmSessionAdapter::GetSession(
   return (session != sessions_.end()) ? session->second.get() : NULL;
 }
 
+void CdmSessionAdapter::ReportCdmCreationTimeUMA(
+    base::TimeDelta cdm_creation_time) {
+  // Note: This leaks memory, which is expected behavior.
+  base::HistogramBase* histogram = base::Histogram::FactoryTimeGet(
+      GetKeySystemUMAPrefix() + kCdmCreationTimeUMAName,
+      base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromSeconds(10),
+      50, base::HistogramBase::kUmaTargetedHistogramFlag);
+
+  histogram->AddTime(cdm_creation_time);
+}
+
 }  // namespace media