Fixes metrics collection during CdmEngine close.

This fixes a problem where a CdmEngine instance (and its sessions) could
be closed before its metrics could be collected. The change allows the
wv_content_decryption_module to extract metrics from instances about to
be closed. These are held until reported to the caller.

Test: Manually verified that collection is now occurring correctly. Also
added unit test: wv_cdm_metric_test.

This is a merge from wvgerrit/29069

Change-Id: If82bfd5cae3b72b9d14ab4741424a7ae7cc0a3a6

libwvdrmengine/build_and_run_all_unit_tests.sh

@@ -102,6 +102,7 @@ try_adb_push request_license_test
 try_adb_push service_certificate_unittest
 try_adb_push timer_unittest
 try_adb_push usage_table_header_unittest
+try_adb_push wv_cdm_metrics_test
 
 # Run the tests using run_all_unit_tests.sh
 cd $ANDROID_BUILD_TOP/vendor/widevine/libwvdrmengine

libwvdrmengine/cdm/core/src/cdm_engine.cpp

@@ -188,7 +188,7 @@ CdmResponseType CdmEngine::OpenKeySetSession(
 }
 
 CdmResponseType CdmEngine::CloseSession(const CdmSessionId& session_id) {
-  LOGI("CdmEngine::CloseSession");
+  LOGV("CdmEngine::CloseSession: %s", session_id.c_str());
   AutoLock lock(session_list_lock_);
   CdmSessionMap::iterator iter = sessions_.find(session_id);
   if (iter == sessions_.end()) {

libwvdrmengine/cdm/include/wv_content_decryption_module.h

@@ -11,6 +11,7 @@
 #include "cdm_identifier.h"
 #include "file_store.h"
 #include "lock.h"
+#include "metrics.pb.h"
 #include "timer.h"
 #include "wv_cdm_types.h"
 
@@ -125,7 +126,8 @@ class WvContentDecryptionModule : public android::RefBase, public TimerHandler {
   // Validate a passed-in service certificate
   virtual bool IsValidServiceCertificate(const std::string& certificate);
 
-  // Retrieve the serialized metrics from the CDM.
+  // Retrieve the serialized metrics from CdmEngine and CdmSession instances
+  // that have been closed.
   virtual void GetSerializedMetrics(std::string* serialized_metrics);
 
  private:
@@ -142,6 +144,10 @@ class WvContentDecryptionModule : public android::RefBase, public TimerHandler {
   // Finds the CdmEngine instance for the given session id, returning NULL if
   // not found.
   CdmEngine* GetCdmForSessionId(const std::string& session_id);
+  // Closes CdmEngine instances that don't have any open sessions. Also stores
+  // metrics data for closed CdmEngine instances.
+  // Callers must acquire the cdms_lock_ before calling this method.
+  void CloseCdmsWithoutSessions();
 
   uint32_t GenerateSessionSharingId();
 
@@ -162,6 +168,9 @@ class WvContentDecryptionModule : public android::RefBase, public TimerHandler {
   // This contains weak pointers to the CDM instances contained in |cdms_|.
   std::map<std::string, CdmEngine*> cdm_by_session_id_;
 
+  // The metrics for cdm engines and sessions that have been closed.
+  drm_metrics::MetricsGroup metrics_;
+
   CORE_DISALLOW_COPY_AND_ASSIGN(WvContentDecryptionModule);
 };
 

libwvdrmengine/cdm/metrics/include/metrics_collections.h

@@ -140,7 +140,7 @@ class CryptoMetrics {
   EventMetric<OEMCryptoResult> oemcrypto_rewrap_device_rsa_key_;
   EventMetric<OEMCryptoResult> oemcrypto_rewrap_device_rsa_key_30_;
   EventMetric<CdmSecurityLevel, SecurityLevel> oemcrypto_security_level_;
-  EventMetric<uint8_t, SecurityLevel> oemcrypto_security_patch_level_;
+  EventMetric<uint16_t, SecurityLevel> oemcrypto_security_patch_level_;
   EventMetric<OEMCryptoResult> oemcrypto_select_key_;
   EventMetric<OEMCryptoResult, SecurityLevel> oemcrypto_supports_usage_table_;
   EventMetric<OEMCryptoResult> oemcrypto_update_usage_table_;

libwvdrmengine/cdm/metrics/src/metrics_collections.cpp

@@ -4,6 +4,7 @@
 
 #include <algorithm>
 
+#include "log.h"
 #include "metrics.pb.h"
 
 using drm_metrics::MetricsGroup;
@@ -438,6 +439,10 @@ EngineMetrics::EngineMetrics() :
 EngineMetrics::~EngineMetrics() {
   AutoLock kock(session_metrics_lock_);
   std::vector<SessionMetrics*>::iterator i;
+  if (!session_metrics_list_.empty()) {
+    LOGV("EngineMetrics::~EngineMetrics. Session count: %d",
+         session_metrics_list_.size());
+  }
   for (i = session_metrics_list_.begin(); i != session_metrics_list_.end();
        i++) {
     delete *i;

libwvdrmengine/cdm/src/wv_content_decryption_module.cpp

@@ -7,7 +7,6 @@
 #include "initialization_data.h"
 #include "license.h"
 #include "log.h"
-#include "metrics.pb.h"
 #include "properties.h"
 #include "service_certificate.h"
 #include "wv_cdm_constants.h"
@@ -24,7 +23,7 @@ Lock WvContentDecryptionModule::session_sharing_id_generation_lock_;
 WvContentDecryptionModule::WvContentDecryptionModule() {}
 
 WvContentDecryptionModule::~WvContentDecryptionModule() {
-  DisablePolicyTimer(true);
+  DisablePolicyTimer(true /* Force. */);
 }
 
 bool WvContentDecryptionModule::IsSupported(const std::string& init_data_type) {
@@ -72,6 +71,7 @@ CdmResponseType WvContentDecryptionModule::OpenSession(
 
 CdmResponseType WvContentDecryptionModule::CloseSession(
     const CdmSessionId& session_id) {
+  LOGV("WvContentDecryptionModule::CloseSession. id: %s", session_id.c_str());
   CdmEngine* cdm_engine = GetCdmForSessionId(session_id);
   // TODO(rfrias): Avoid reusing the error codes from CdmEngine.
   if (!cdm_engine) return SESSION_NOT_FOUND_1;
@@ -85,7 +85,9 @@ CdmResponseType WvContentDecryptionModule::CloseSession(
   if (sts == NO_ERROR) {
     cdm_by_session_id_.erase(session_id);
   }
-  DisablePolicyTimer(false);
+
+  DisablePolicyTimer(false /* Do not force. */);
+
   return sts;
 }
 
@@ -399,21 +401,10 @@ bool WvContentDecryptionModule::IsValidServiceCertificate(
 
 void WvContentDecryptionModule::GetSerializedMetrics(
     std::string* serialized_metrics) {
-  drm_metrics::MetricsGroup metric_group;
-  {
-    AutoLock auto_lock(cdms_lock_);
-    for (auto it = cdms_.begin(); it != cdms_.end(); it++) {
-      metrics::EngineMetrics* engine_metrics =
-          it->second.cdm_engine->GetMetrics();
-      if (engine_metrics) {
-        // Serialize the metrics from the engine and any completed sessions.
-        // Clear the metrics from any completed sessions.
-        engine_metrics->Serialize(
-            metric_group.add_metric_sub_group(), true, true);
-      }
-    }
-  }
-  metric_group.SerializeToString(serialized_metrics);
+  AutoLock auto_lock(cdms_lock_);
+  CloseCdmsWithoutSessions();
+  metrics_.SerializeToString(serialized_metrics);
+  metrics_.Clear();
 }
 
 WvContentDecryptionModule::CdmInfo::CdmInfo()
@@ -444,6 +435,34 @@ CdmEngine* WvContentDecryptionModule::GetCdmForSessionId(
   return it->second;
 }
 
+// This method requires that the caller first acquire cdms_lock_.
+void WvContentDecryptionModule::CloseCdmsWithoutSessions() {
+  for (auto it = cdms_.begin(); it != cdms_.end();) {
+    if (it->second.cdm_engine->SessionSize() != 0) {
+      ++it;
+    } else {
+      // Retrieve the metrics from the engine and any completed
+      // sessions. Clear the metrics from any completed sessions.
+      metrics::EngineMetrics* engine_metrics =
+          it->second.cdm_engine->GetMetrics();
+      // engine_metrics should never be null.
+      if (engine_metrics != NULL) {
+        engine_metrics->Serialize(
+            metrics_.add_metric_sub_group(),
+            false,  // Report complete AND incomplete sessions.
+            true);  // Clear session metrics after reporting.
+      } else {
+        // Engine metrics should never be null.
+        LOGI("WvContentDecryptionModule::CloseCdmsWithoutSessions."
+             "engine_metrics was unexpectedly NULL.");
+      }
+
+      // The CDM is no longer used for this identifier, delete it.
+      it = cdms_.erase(it);
+    }
+  }
+}
+
 void WvContentDecryptionModule::EnablePolicyTimer() {
   AutoLock auto_lock(policy_timer_lock_);
   if (!policy_timer_.IsRunning())
@@ -451,23 +470,19 @@ void WvContentDecryptionModule::EnablePolicyTimer() {
 }
 
 void WvContentDecryptionModule::DisablePolicyTimer(bool force) {
-  bool has_sessions = false;
+  bool cdms_is_empty = false;
   {
     AutoLock auto_lock(cdms_lock_);
-    for (auto it = cdms_.begin(); it != cdms_.end();) {
-      if (it->second.cdm_engine->SessionSize() != 0) {
-        has_sessions = true;
-        ++it;
-      } else {
-        // The CDM is no longer used for this identifier, delete it.
-        it = cdms_.erase(it);
-      }
-    }
+    CloseCdmsWithoutSessions();
+    cdms_is_empty = cdms_.empty();
   }
 
   AutoLock auto_lock(policy_timer_lock_);
-  if ((!has_sessions || force) && policy_timer_.IsRunning())
-    policy_timer_.Stop();
+  if(force || cdms_is_empty) {
+    if (policy_timer_.IsRunning()) {
+      policy_timer_.Stop();
+    }
+  }
 }
 
 void WvContentDecryptionModule::OnTimerEvent() {

libwvdrmengine/cdm/test/Android.mk

@@ -75,6 +75,10 @@ test_name := usage_table_header_unittest
 test_src_dir := ../core/test
 include $(LOCAL_PATH)/unit-test.mk
 
+test_name := wv_cdm_metrics_test
+test_src_dir := .
+include $(LOCAL_PATH)/unit-test.mk
+
 test_name := distribution_test
 test_src_dir := ../metrics/test
 include $(LOCAL_PATH)/unit-test.mk

libwvdrmengine/cdm/test/wv_cdm_metrics_test.cpp

@@ -0,0 +1,144 @@
+// Copyright 2017 Google Inc. All Rights Reserved.
+//
+// This file contains unit tests for the WvContentDecryptionModule class
+// that pertain to collecting and reporting metrics.
+
+#include "gmock/gmock.h"
+#include "log.h"
+#include "metrics.pb.h"
+#include "test_base.h"
+#include "test_printers.h"
+#include "wv_cdm_types.h"
+#include "wv_content_decryption_module.h"
+
+using ::testing::Eq;
+using ::testing::StrEq;
+using ::testing::Gt;
+using ::testing::Test;
+using wvcdm::CdmResponseType;
+
+namespace wvcdm {
+
+// This class is used to test the metrics-related feaures of the
+// WvContentDecryptionModule class.
+class WvContentDecryptionModuleMetricsTest : public ::testing::Test {
+ protected:
+
+  wvcdm::WvContentDecryptionModule decryptor_;
+};
+
+TEST_F(WvContentDecryptionModuleMetricsTest, NoMetrics) {
+  // Get metrics before any operations are performed.
+  std::string serialized_metrics;
+  decryptor_.GetSerializedMetrics(&serialized_metrics);
+  EXPECT_TRUE(serialized_metrics.empty());
+}
+
+TEST_F(WvContentDecryptionModuleMetricsTest, EngineOnlyMetrics) {
+  std::string request;
+  std::string provisioning_server_url;
+  CdmCertificateType cert_type = kCertificateWidevine;
+  std::string cert_authority, cert, wrapped_key;
+
+  // This call will create a CdmEngine instance with an EngineMetrics instance.
+  EXPECT_EQ(wvcdm::NO_ERROR,
+            decryptor_.GetProvisioningRequest(cert_type, cert_authority,
+                                              kDefaultCdmIdentifier, &request,
+                                              &provisioning_server_url));
+  std::string serialized_metrics;
+  decryptor_.GetSerializedMetrics(&serialized_metrics);
+
+  // Spot check some metric values.
+  drm_metrics::MetricsGroup metrics;
+  ASSERT_TRUE(metrics.ParseFromString(serialized_metrics));
+  EXPECT_THAT(metrics.metric_size(), Eq(0));
+  ASSERT_THAT(metrics.metric_sub_group_size(), Eq(1));
+  ASSERT_THAT(metrics.metric_sub_group(0).metric_size(), Gt(0));
+  EXPECT_THAT(metrics.metric_sub_group(0).metric_sub_group_size(), Eq(0));
+  EXPECT_THAT(
+      metrics.metric_sub_group(0).metric(0).name(),
+      StrEq("/drm/widevine/cdm_engine/"
+            "get_provisioning_request/time/count{error:0}"));
+  EXPECT_THAT(metrics.metric_sub_group(0).metric(0).value().int_value(), Eq(1));
+}
+
+
+TEST_F(WvContentDecryptionModuleMetricsTest, EngineAndSessionMetrics) {
+  CdmSessionId session_id;
+  wvcdm::CdmKeySystem key_system("com.widevine");
+
+  // Openning the session will fail with NEEDS_PROVISIONING error. But it will
+  // still create some session-level stats.
+  EXPECT_EQ(CdmResponseType::NEED_PROVISIONING,
+            decryptor_.OpenSession(key_system, NULL,
+                                   kDefaultCdmIdentifier, NULL, &session_id));
+
+  // The metrics will have a single engine and single session stats.
+  std::string serialized_metrics;
+  decryptor_.GetSerializedMetrics(&serialized_metrics);
+
+  // Spot check some metric values.
+  drm_metrics::MetricsGroup metrics;
+  ASSERT_TRUE(metrics.ParseFromString(serialized_metrics));
+  // The outer container will never have metrics.
+  EXPECT_THAT(metrics.metric_size(), Eq(0));
+  ASSERT_THAT(metrics.metric_sub_group_size(), Eq(1));
+  ASSERT_THAT(metrics.metric_sub_group(0).metric_size(), Gt(0));
+
+  // Validate an engine-level metric.
+  EXPECT_THAT(
+      metrics.metric_sub_group(0).metric(0).name(),
+      StrEq("/drm/widevine/cdm_engine/open_session/time/count{error:7}"));
+  EXPECT_THAT(metrics.metric_sub_group(0).metric(0).value().int_value(), Eq(1));
+
+  // Validate a session-level metric.
+  EXPECT_THAT(metrics.metric_sub_group(0).metric_sub_group_size(), Eq(1));
+  EXPECT_THAT(
+      metrics.metric_sub_group(0).metric_sub_group(0).metric(0).name(),
+      StrEq("/drm/widevine/cdm_session/session_id"));
+}
+
+TEST_F(WvContentDecryptionModuleMetricsTest, MultipleEngineMetric) {
+  CdmSessionId session_id;
+  wvcdm::CdmKeySystem key_system("com.widevine");
+  CdmIdentifier identifier = { "foo", "bar" };
+
+  // Openning the session will fail with NEEDS_PROVISIONING error. But it will
+  // still create some session-level stats.
+  EXPECT_EQ(CdmResponseType::NEED_PROVISIONING,
+            decryptor_.OpenSession(key_system, NULL,
+                                   kDefaultCdmIdentifier, NULL, &session_id));
+  // Open a second engine with a custom identifier.
+  EXPECT_EQ(CdmResponseType::NEED_PROVISIONING,
+            decryptor_.OpenSession(key_system, NULL,
+                                   identifier, NULL, &session_id));
+
+  // The metrics will now have two engines with single session stats each.
+  std::string serialized_metrics;
+  decryptor_.GetSerializedMetrics(&serialized_metrics);
+
+  // Spot check some metric values.
+  drm_metrics::MetricsGroup metrics;
+  ASSERT_TRUE(metrics.ParseFromString(serialized_metrics));
+  // The outer container will never have metrics.
+  EXPECT_THAT(metrics.metric_size(), Eq(0));
+
+  // Two engine-level metrics are expected.
+  ASSERT_THAT(metrics.metric_sub_group_size(), Eq(2));
+
+  for (int i = 0; i < metrics.metric_sub_group_size(); i++) {
+    // Validate the engine-level metric.
+    ASSERT_THAT(metrics.metric_sub_group(i).metric_size(), Gt(0));
+    EXPECT_THAT(
+        metrics.metric_sub_group(i).metric(0).name(),
+        StrEq("/drm/widevine/cdm_engine/open_session/time/count{error:7}"));
+    EXPECT_THAT(metrics.metric_sub_group(i).metric(0).value().int_value(), Eq(1));
+    // Validate a session-level metric.
+    EXPECT_THAT(metrics.metric_sub_group(i).metric_sub_group_size(), Eq(1));
+    EXPECT_THAT(
+        metrics.metric_sub_group(i).metric_sub_group(0).metric(0).name(),
+        StrEq("/drm/widevine/cdm_session/session_id"));
+  }
+}
+
+}

libwvdrmengine/mediacrypto/Android.mk

@@ -22,6 +22,7 @@ LOCAL_HEADER_LIBRARIES := \
   libutils_headers
 
 LOCAL_STATIC_LIBRARIES := \
+  libcdm_protos \
   libcrypto_static \
 
 LOCAL_SHARED_LIBRARIES := \
@@ -58,6 +59,7 @@ LOCAL_HEADER_LIBRARIES := \
   libutils_headers
 
 LOCAL_STATIC_LIBRARIES := \
+  libcdm_protos \
   libcrypto_static \
   libwidevinehidl_utils \
 

libwvdrmengine/mediadrm/Android.mk

@@ -25,6 +25,9 @@ LOCAL_HEADER_LIBRARIES := \
 LOCAL_SHARED_LIBRARIES := \
   liblog
 
+LOCAL_STATIC_LIBRARIES := \
+  libcdm_protos
+
 LOCAL_MODULE := libwvdrmdrmplugin
 LOCAL_PROPRIETARY_MODULE := true
 
@@ -56,7 +59,9 @@ LOCAL_C_INCLUDES := \
 LOCAL_HEADER_LIBRARIES := \
   libutils_headers \
 
-LOCAL_STATIC_LIBRARIES := libcrypto_static
+LOCAL_STATIC_LIBRARIES := \
+  libcdm_protos \
+  libcrypto_static
 
 LOCAL_SHARED_LIBRARIES := \
   android.hardware.drm@1.0 \

libwvdrmengine/run_all_unit_tests.sh

@@ -98,6 +98,7 @@ adb_shell_run policy_engine_unittest
 adb_shell_run service_certificate_unittest
 adb_shell_run timer_unittest
 adb_shell_run usage_table_header_unittest
+adb_shell_run wv_cdm_metrics_test
 
 # Run the non-Treble test on non-Treble devices
 if adb shell ls /vendor/lib/mediadrm/libwvdrmengine.so &> /dev/null ||