Merge changes If99c1873,I3a3aa4fb into pi-dev

* changes:
  Creates a new license request latency metric
  Fixes missing or broken metrics in Widevine CDM

libwvdrmengine/cdm/core/include/cdm_engine.h

@@ -18,7 +18,6 @@
 #include "oemcrypto_adapter.h"
 #include "scoped_ptr.h"
 #include "service_certificate.h"
-#include "timer_metric.h"
 #include "wv_cdm_constants.h"
 #include "wv_cdm_types.h"
 
@@ -316,7 +315,6 @@ class CdmEngine {
    * it is published.
    */
   metrics::EngineMetrics metrics_;
-  metrics::TimerMetric life_span_;
 
   CdmSessionMap session_map_;
   CdmReleaseKeySetMap release_key_sets_;

libwvdrmengine/cdm/core/include/cdm_session.h

@@ -199,6 +199,12 @@ class CdmSession {
 
   bool UpdateUsageInfo();
 
+  CdmResponseType GenerateKeyRequestInternal(
+      const InitializationData& init_data, CdmLicenseType license_type,
+      const CdmAppParameterMap& app_parameters, CdmKeyRequest* key_request);
+  virtual CdmResponseType AddKeyInternal(const CdmKeyResponse& key_response);
+  void UpdateRequestLatencyTiming(CdmResponseType sts);
+
   // These setters are for testing only. Takes ownership of the pointers.
   void set_license_parser(CdmLicense* license_parser);
   void set_crypto_session(CryptoSession* crypto_session);
@@ -209,6 +215,8 @@ class CdmSession {
   metrics::SessionMetrics* metrics_;
   metrics::CryptoMetrics* crypto_metrics_;
   metrics::TimerMetric life_span_;
+  metrics::TimerMetric license_request_latency_;
+  CdmKeyRequestType key_request_type_;
 
   bool initialized_;
   bool closed_;  // Session closed, but final shared_ptr has not been released.

libwvdrmengine/cdm/core/include/usage_table_header.h

@@ -51,22 +51,23 @@ class UsageTableHeader {
   bool Init(CdmSecurityLevel security_level, CryptoSession* crypto_session);
 
   // |persistent_license| false indicates usage info record
-  CdmResponseType AddEntry(CryptoSession* crypto_session,
-                           bool persistent_license,
-                           const CdmKeySetId& key_set_id,
-                           const std::string& usage_info_filename,
-                           uint32_t* usage_entry_number);
-  CdmResponseType LoadEntry(CryptoSession* crypto_session,
-                            const CdmUsageEntry& usage_entry,
-                            uint32_t usage_entry_number);
-  CdmResponseType UpdateEntry(CryptoSession* crypto_session,
-                              CdmUsageEntry* usage_entry);
+  virtual CdmResponseType AddEntry(CryptoSession* crypto_session,
+                                   bool persistent_license,
+                                   const CdmKeySetId& key_set_id,
+                                   const std::string& usage_info_filename,
+                                   uint32_t* usage_entry_number);
+  virtual CdmResponseType LoadEntry(CryptoSession* crypto_session,
+                                   const CdmUsageEntry& usage_entry,
+                                   uint32_t usage_entry_number);
+  virtual CdmResponseType UpdateEntry(CryptoSession* crypto_session,
+                                      CdmUsageEntry* usage_entry);
 
   // The licenses or usage info records specified by |usage_entry_number|
   // should not be in use by any open CryptoSession objects when calls
   // to DeleteEntry and MoveEntry are made.
-  CdmResponseType DeleteEntry(uint32_t usage_entry_number, DeviceFiles* handle,
-                              metrics::CryptoMetrics* metrics);
+  virtual CdmResponseType DeleteEntry(uint32_t usage_entry_number,
+                                      DeviceFiles* handle,
+                                      metrics::CryptoMetrics* metrics);
 
  private:
   CdmResponseType MoveEntry(uint32_t from /* usage entry number */,

libwvdrmengine/cdm/core/src/cdm_engine.cpp

@@ -70,7 +70,6 @@ CdmEngine::CdmEngine(FileSystem* file_system, const std::string& spoid)
     seeded_ = true;
   }
 
-  life_span_.Start();
   metrics_.cdm_engine_creation_time_millis_.Record(clock_.GetCurrentTime());
 
   std::string cdm_version;
@@ -82,9 +81,7 @@ CdmEngine::CdmEngine(FileSystem* file_system, const std::string& spoid)
   }
 }
 
-CdmEngine::~CdmEngine() {
-  M_RECORD(&metrics_, cdm_engine_life_span_, life_span_.AsMs());
-}
+CdmEngine::~CdmEngine() {}
 
 CdmResponseType CdmEngine::SetProvisioningServiceCertificate(
     const std::string& certificate) {

libwvdrmengine/cdm/core/src/cdm_session.cpp

@@ -324,7 +324,23 @@ CdmResponseType CdmSession::RestoreUsageSession(
   return KEY_ADDED;
 }
 
+// This is a thin wrapper that initiates the latency metric.
 CdmResponseType CdmSession::GenerateKeyRequest(
+    const InitializationData& init_data, CdmLicenseType license_type,
+    const CdmAppParameterMap& app_parameters, CdmKeyRequest* key_request) {
+  CdmResponseType result = GenerateKeyRequestInternal(
+      init_data, license_type, app_parameters, key_request);
+  // Note that GenerateReleaseRequest and GenerateRenewalRequest will initialize
+  // the timer themselves. This is duplicate because there are duplicate paths
+  // for calling GenerateReleaseRequest and GenerateRenewalRequest.
+  if (result == KEY_MESSAGE) {
+    key_request_type_ = key_request->type;
+    license_request_latency_.Start(); // Start or restart timer.
+  }
+  return result;
+}
+
+CdmResponseType CdmSession::GenerateKeyRequestInternal(
     const InitializationData& init_data, CdmLicenseType license_type,
     const CdmAppParameterMap& app_parameters,
     CdmKeyRequest* key_request) {
@@ -410,8 +426,15 @@ CdmResponseType CdmSession::GenerateKeyRequest(
   }
 }
 
-// AddKey() - Accept license response and extract key info.
+// This thin wrapper allows us to update metrics.
 CdmResponseType CdmSession::AddKey(const CdmKeyResponse& key_response) {
+  CdmResponseType sts = AddKeyInternal(key_response);
+  UpdateRequestLatencyTiming(sts);
+  return sts;
+}
+
+// AddKeyInternal() - Accept license response and extract key info.
+CdmResponseType CdmSession::AddKeyInternal(const CdmKeyResponse& key_response) {
   if (!initialized_) {
     LOGE("CdmSession::AddKey: not initialized");
     return NOT_INITIALIZED_ERROR;
@@ -602,6 +625,8 @@ CdmResponseType CdmSession::GenerateRenewalRequest(
   if (is_offline_) {
     offline_key_renewal_request_ = key_request->message;
   }
+  key_request_type_ = key_request->type;
+  license_request_latency_.Start(); // Start or restart timer.
   return KEY_MESSAGE;
 }
 
@@ -613,6 +638,10 @@ CdmResponseType CdmSession::RenewKey(const CdmKeyResponse& key_response) {
   }
   CdmResponseType sts =
       license_parser_->HandleKeyUpdateResponse(true, key_response);
+
+  // Record the timing on success.
+  UpdateRequestLatencyTiming(sts);
+
   if (sts != KEY_ADDED) return (sts == KEY_ERROR) ? RENEW_KEY_ERROR_1 : sts;
 
   if (is_offline_) {
@@ -630,6 +659,7 @@ CdmResponseType CdmSession::GenerateReleaseRequest(
     return NOT_INITIALIZED_ERROR;
   }
   is_release_ = true;
+  license_request_latency_.Clear();
   CdmResponseType status = license_parser_->PrepareKeyUpdateRequest(
       false, app_parameters_, usage_table_header_ == NULL ? NULL : this,
       &key_request->message, &key_request->url);
@@ -658,6 +688,10 @@ CdmResponseType CdmSession::GenerateReleaseRequest(
         return RELEASE_USAGE_INFO_FAILED;
     }
   }
+
+  key_request_type_ = key_request->type;
+  license_request_latency_.Start(); // Start or restart timer.
+
   return KEY_MESSAGE;
 }
 
@@ -669,6 +703,9 @@ CdmResponseType CdmSession::ReleaseKey(const CdmKeyResponse& key_response) {
   }
   CdmResponseType sts =
       license_parser_->HandleKeyUpdateResponse(false, key_response);
+  // Record the timing on success.
+  UpdateRequestLatencyTiming(sts);
+
   if (sts != KEY_ADDED) return (sts == KEY_ERROR) ? RELEASE_KEY_ERROR : sts;
 
   if (is_offline_ || has_provider_session_token()) {
@@ -916,8 +953,13 @@ CdmResponseType CdmSession::UpdateUsageEntryInformation() {
     return INCORRECT_USAGE_SUPPORT_TYPE_2;
   }
 
-  CdmResponseType sts = usage_table_header_->UpdateEntry(crypto_session_.get(),
-                                                         &usage_entry_);
+  CdmResponseType sts = NO_ERROR;
+  M_TIME(
+    sts = usage_table_header_->UpdateEntry(crypto_session_.get(),
+                                           &usage_entry_),
+    crypto_metrics_,
+    crypto_session_update_usage_entry_,
+    sts);
 
   if (sts != NO_ERROR) return sts;
 
@@ -1041,6 +1083,14 @@ bool CdmSession::UpdateUsageInfo() {
       usage_data);
 }
 
+void CdmSession::UpdateRequestLatencyTiming(CdmResponseType sts) {
+  if (sts == KEY_ADDED && license_request_latency_.IsStarted()) {
+    metrics_->cdm_session_license_request_latency_ms_.Record(
+        license_request_latency_.AsMs(), key_request_type_);
+  }
+  license_request_latency_.Clear();
+}
+
 // For testing only - takes ownership of pointers
 
 void CdmSession::set_license_parser(CdmLicense* license_parser) {

libwvdrmengine/cdm/core/src/crypto_session.cpp

@@ -2093,6 +2093,7 @@ CdmResponseType CryptoSession::UpdateUsageEntry(
   size_t usage_entry_len = 0;
   OEMCryptoResult result = OEMCrypto_UpdateUsageEntry(
       oec_session_id_, NULL, &usage_table_header_len, NULL, &usage_entry_len);
+  metrics_->oemcrypto_update_usage_entry_.Increment(result);
 
   if (result == OEMCrypto_ERROR_SHORT_BUFFER) {
     usage_table_header->resize(usage_table_header_len);
@@ -2105,6 +2106,7 @@ CdmResponseType CryptoSession::UpdateUsageEntry(
         &usage_table_header_len,
         reinterpret_cast<uint8_t*>(const_cast<char*>(usage_entry->data())),
         &usage_entry_len);
+    metrics_->oemcrypto_update_usage_entry_.Increment(result);
   }
 
   if (result != OEMCrypto_SUCCESS) {

libwvdrmengine/cdm/core/test/cdm_engine_test.cpp

@@ -15,6 +15,7 @@
 #include "file_store.h"
 #include "license_request.h"
 #include "log.h"
+#include "metrics.pb.h"
 #include "OEMCryptoCENC.h"
 #include "properties.h"
 #include "scoped_ptr.h"
@@ -26,6 +27,9 @@
 
 namespace wvcdm {
 
+using drm_metrics::WvCdmMetrics;
+using drm_metrics::DistributionMetric;
+
 namespace {
 
 // Http OK response code.
@@ -460,12 +464,43 @@ class WvCdmEngineTest : public WvCdmEnginePreProvTest {
     CdmKeySetId key_set_id;
     EXPECT_EQ(KEY_ADDED,
               cdm_engine_.AddKey(session_id_, resp, &key_set_id));
+    VerifyLicenseRequestLatency(CdmKeyRequestType::kKeyRequestTypeInitial,
+                                *cdm_engine_.GetMetrics());
   }
 
   void VerifyRenewalKeyResponse(const std::string& server_url,
                                 const std::string& client_auth) {
     std::string resp = GetKeyRequestResponse(server_url, client_auth);
     EXPECT_EQ(KEY_ADDED, cdm_engine_.RenewKey(session_id_, resp));
+    VerifyLicenseRequestLatency(CdmKeyRequestType::kKeyRequestTypeRenewal,
+                                *cdm_engine_.GetMetrics());
+  }
+
+  void VerifyLicenseRequestLatency(
+      CdmKeyRequestType key_request_type,
+      const metrics::EngineMetrics& engine_metrics) {
+    WvCdmMetrics metrics_proto;
+    engine_metrics.Serialize(&metrics_proto);
+    bool has_request_type = false;
+    for (int i = 0; i < metrics_proto.session_metrics_size(); i++) {
+      WvCdmMetrics::SessionMetrics session_metrics =
+          metrics_proto.session_metrics(i);
+      for (int j = 0;
+           j < session_metrics.cdm_session_license_request_latency_ms_size();
+           j++) {
+        DistributionMetric latency_distribution =
+            session_metrics.cdm_session_license_request_latency_ms(j);
+        if (latency_distribution.attributes().key_request_type()
+            == key_request_type && latency_distribution.operation_count() > 0) {
+          has_request_type = true;
+        }
+      }
+    }
+    std::string serialized_metrics;
+    ASSERT_TRUE(metrics_proto.SerializeToString(&serialized_metrics));
+    EXPECT_TRUE(has_request_type)
+        << "Expected request type " << key_request_type << " was not found. "
+        << "metrics: " << wvcdm::b2a_hex(serialized_metrics);
   }
 
   std::string server_url_;

libwvdrmengine/cdm/core/test/cdm_session_unittest.cpp

@@ -4,13 +4,25 @@
 #include <gtest/gtest.h>
 #include "cdm_session.h"
 #include "crypto_key.h"
+#include "metrics.pb.h"
 #include "properties.h"
 #include "scoped_ptr.h"
 #include "service_certificate.h"
 #include "string_conversions.h"
 #include "test_printers.h"
+#include "usage_table_header.h"
 #include "wv_cdm_constants.h"
 
+using ::testing::_;
+using ::testing::Eq;
+using ::testing::Invoke;
+using ::testing::NiceMock;
+using ::testing::NotNull;
+using ::testing::Return;
+using ::testing::SetArgPointee;
+using ::testing::Sequence;
+using ::testing::StrEq;
+
 namespace wvcdm {
 
 namespace {
@@ -100,10 +112,23 @@ class MockDeviceFiles : public DeviceFiles {
                                          std::string*, uint32_t*));
 };
 
+class MockUsageTableHeader : public UsageTableHeader {
+ public:
+  MockUsageTableHeader() : UsageTableHeader() {}
+
+  MOCK_METHOD2(UpdateEntry, CdmResponseType(CryptoSession* crypto_session,
+                                            CdmUsageEntry* usage_entry));
+};
+
 class MockCryptoSession : public CryptoSession {
  public:
   MockCryptoSession(metrics::CryptoMetrics* crypto_metrics)
-      : CryptoSession(crypto_metrics) { }
+      : CryptoSession(crypto_metrics) {
+    // By default, call the concrete implementation of GetUsageSupportType.
+    ON_CALL(*this, GetUsageSupportType(_))
+        .WillByDefault(
+            Invoke(this, &MockCryptoSession::BaseGetUsageSupportType));
+  }
   MOCK_METHOD1(GetClientToken, bool(std::string*));
   MOCK_METHOD1(GetProvisioningToken, bool(std::string*));
   MOCK_METHOD0(GetPreProvisionTokenType, CdmClientTokenType());
@@ -112,6 +137,12 @@ class MockCryptoSession : public CryptoSession {
   MOCK_METHOD1(Open, CdmResponseType(SecurityLevel));
   MOCK_METHOD1(LoadCertificatePrivateKey, bool(std::string&));
   MOCK_METHOD0(DeleteAllUsageReports, CdmResponseType());
+  MOCK_METHOD1(GetUsageSupportType, CdmResponseType(CdmUsageSupportType* type));
+  MOCK_METHOD0(GetUsageTableHeader, UsageTableHeader*());
+
+  CdmResponseType BaseGetUsageSupportType(CdmUsageSupportType* type) {
+    return CryptoSession::GetUsageSupportType(type);
+  }
 };
 
 class MockPolicyEngine : public PolicyEngine {
@@ -129,19 +160,11 @@ class MockCdmLicense : public CdmLicense {
   MOCK_METHOD7(Init, bool(const std::string&, CdmClientTokenType,
                           const std::string&, bool, const std::string&,
                           CryptoSession*, PolicyEngine*));
+  MOCK_METHOD0(provider_session_token, std::string());
 };
 
 }  // namespace
 
-// gmock methods
-using ::testing::_;
-using ::testing::Eq;
-using ::testing::NotNull;
-using ::testing::Return;
-using ::testing::SetArgPointee;
-using ::testing::Sequence;
-using ::testing::StrEq;
-
 class CdmSessionTest : public ::testing::Test {
  protected:
   virtual void SetUp() {
@@ -149,7 +172,7 @@ class CdmSessionTest : public ::testing::Test {
     // Inject testing mocks.
     license_parser_ = new MockCdmLicense(cdm_session_->session_id());
     cdm_session_->set_license_parser(license_parser_);
-    crypto_session_ = new MockCryptoSession(&crypto_metrics_);
+    crypto_session_ = new NiceMock<MockCryptoSession>(&crypto_metrics_);
     cdm_session_->set_crypto_session(crypto_session_);
     policy_engine_ = new MockPolicyEngine();
     cdm_session_->set_policy_engine(policy_engine_);
@@ -167,9 +190,10 @@ class CdmSessionTest : public ::testing::Test {
   scoped_ptr<CdmSession> cdm_session_;
   MockCdmLicense* license_parser_;
   metrics::CryptoMetrics crypto_metrics_;
-  MockCryptoSession* crypto_session_;
+  NiceMock<MockCryptoSession>* crypto_session_;
   MockPolicyEngine* policy_engine_;
   MockDeviceFiles* file_handle_;
+  MockUsageTableHeader usage_table_header_;
 };
 
 TEST_F(CdmSessionTest, InitWithBuiltInCertificate) {
@@ -282,4 +306,56 @@ TEST_F(CdmSessionTest, InitNeedsProvisioning) {
   ASSERT_EQ(NEED_PROVISIONING, cdm_session_->Init(NULL));
 }
 
+TEST_F(CdmSessionTest, UpdateUsageEntry) {
+  // Setup common expectations for initializing the CdmSession object.
+  Sequence crypto_session_seq;
+  CdmSecurityLevel level = kSecurityLevelL1;
+  EXPECT_CALL(*crypto_session_, Open(Eq(kLevelDefault)))
+      .InSequence(crypto_session_seq)
+      .WillOnce(Return(NO_ERROR));
+  EXPECT_CALL(*crypto_session_, GetSecurityLevel())
+      .InSequence(crypto_session_seq)
+      .WillOnce(Return(level));
+  EXPECT_CALL(*crypto_session_, GetPreProvisionTokenType())
+      .WillOnce(Return(kClientTokenKeybox));
+  EXPECT_CALL(*file_handle_, Init(Eq(level))).WillOnce(Return(true));
+  EXPECT_CALL(*file_handle_, RetrieveCertificate(NotNull(), NotNull(),
+                                                 NotNull(), _))
+      .WillOnce(DoAll(SetArgPointee<0>(kToken), SetArgPointee<1>(kWrappedKey),
+                      Return(true)));
+  EXPECT_CALL(*crypto_session_, LoadCertificatePrivateKey(StrEq(kWrappedKey)))
+      .InSequence(crypto_session_seq)
+      .WillOnce(Return(true));
+  EXPECT_CALL(*crypto_session_, GetUsageTableHeader())
+      .WillOnce(Return(&usage_table_header_));
+  EXPECT_CALL(*license_parser_,
+              Init(Eq(kToken), Eq(kClientTokenDrmCert), Eq(kEmptyString),
+                   false, Eq(kEmptyString), Eq(crypto_session_),
+                   Eq(policy_engine_)))
+      .WillOnce(Return(true));
+
+  // Set up mocks and expectations for the UpdateUsageEntryInformation call.
+  EXPECT_CALL(*crypto_session_, GetUsageSupportType(_))
+      .WillOnce(DoAll(SetArgPointee<0>(kUsageEntrySupport), Return(NO_ERROR)));
+  EXPECT_CALL(*license_parser_, provider_session_token())
+      .WillOnce(Return("Mock provider session token"));
+  EXPECT_CALL(usage_table_header_, UpdateEntry(NotNull(), NotNull()))
+      .WillOnce(Return(NO_ERROR));
+
+  EXPECT_EQ(NO_ERROR, cdm_session_->Init(NULL));
+  EXPECT_EQ(kUsageEntrySupport, cdm_session_->get_usage_support_type())
+      << "Usage support type: " << cdm_session_->get_usage_support_type();
+  EXPECT_EQ(NO_ERROR, cdm_session_->UpdateUsageEntryInformation());
+
+  // Verify the UsageEntry metric is set.
+  drm_metrics::WvCdmMetrics::SessionMetrics metrics;
+  cdm_session_->GetMetrics()->Serialize(&metrics);
+  std::string serialized_metrics;
+  ASSERT_TRUE(metrics.SerializeToString(&serialized_metrics));
+  EXPECT_GT(metrics.crypto_metrics()
+            .crypto_session_update_usage_entry_time_us().size(), 0)
+      << "Missing update usage entry metric. Metrics: "
+      << wvcdm::b2a_hex(serialized_metrics);
+}
+
 }  // namespace wvcdm