Fixes for query information and usage reporting

* The Usage APIs return usage reports from either L1 or L3 (if available).
* Correction to when usage reports are saved. In addition to other events
  they are now saved when keys are loaded, usage reports are released and soon
  after first decryption and periodically (60 seconds) after that,
  if decryption takes place.
* Usage reports now get deleted on an unprovision request.
* Policy timer is now started when offline licenses are restored.
* Usage session is now released, when a usage response is received.
* Usage tests ahev been enabled.
* Added CDM extended duration (integration) tests to test usage reporting
  and querying. These need to be run manually as they take a while (currently
  half an hour).

b/15592374

[ Merge of https://widevine-internal-review.googlesource.com/#/c/10800
  from the Widevine CDM repo ]

Change-Id: Ia817e03ebbe880e08ba7b4a235ecb82b3ff35fbf

libwvdrmengine/cdm/core/src/cdm_engine.cpp

@@ -25,13 +25,36 @@ namespace {
 
 namespace wvcdm {
 
+class UsagePropertySet : public CdmClientPropertySet {
+ public:
+  UsagePropertySet() {}
+  virtual ~UsagePropertySet() {}
+  void set_security_level(SecurityLevel security_level) {
+    if (kLevel3 == security_level)
+      security_level_ = QUERY_VALUE_SECURITY_LEVEL_L3;
+    else
+      security_level_.clear();
+  }
+  virtual const std::string& security_level() const { return security_level_; }
+  virtual bool use_privacy_mode() const { return false; }
+  virtual const std::string& service_certificate() const { return empty_; }
+  virtual bool is_session_sharing_enabled() const { return false; }
+  virtual uint32_t session_sharing_id() const { return 0; }
+  virtual void set_session_sharing_id(uint32_t id) {
+    id;  // noop to suppress warning
+  }
+ private:
+  std::string security_level_;
+  const std::string empty_;
+};
+
 bool CdmEngine::seeded_ = false;
 
 CdmEngine::CdmEngine()
     : cert_provisioning_(NULL),
       cert_provisioning_requested_security_level_(kLevelDefault),
       usage_session_(NULL),
-      last_usage_information_update_time(0) {
+      last_usage_information_update_time_(0) {
   Properties::Init();
   if (!seeded_) {
     Clock clock;
@@ -269,7 +292,7 @@ CdmResponseType CdmEngine::RestoreKey(
   LOGI("CdmEngine::RestoreKey");
 
   if (key_set_id.empty()) {
-    LOGI("CdmEngine::RestoreKey: invalid key set id");
+    LOGE("CdmEngine::RestoreKey: invalid key set id");
     return KEY_ERROR;
   }
 
@@ -286,6 +309,9 @@ CdmResponseType CdmEngine::RestoreKey(
     cert_provisioning_requested_security_level_ =
         iter->second->GetRequestedSecurityLevel();
   }
+  if (KEY_ADDED != sts) {
+    LOGE("CdmEngine::RestoreKey: restore offline session error = %d", sts);
+  }
   return sts;
 }
 
@@ -539,11 +565,46 @@ CdmResponseType CdmEngine::Unprovision(CdmSecurityLevel security_level) {
     LOGE("CdmEngine::Unprovision: unable to delete files");
     return UNKNOWN_ERROR;
   }
-  return NO_ERROR;
+
+  scoped_ptr<CryptoSession> crypto_session(new CryptoSession());
+  CdmResponseType status = crypto_session->Open(
+      security_level == kSecurityLevelL3 ? kLevel3 : kLevelDefault);
+  if (NO_ERROR != status) {
+    LOGE("CdmEngine::Unprovision: error opening crypto session: %d", status);
+    return UNKNOWN_ERROR;
+  }
+  status = crypto_session->DeleteAllUsageReports();
+  if (status != NO_ERROR) {
+    LOGE("CdmEngine::Unprovision: error deleteing usage reports: %d", status);
+  }
+  return status;
 }
 
 CdmResponseType CdmEngine::GetUsageInfo(CdmUsageInfo* usage_info) {
-  usage_session_.reset(new CdmSession(NULL));
+  // Return a random usage report from a random security level
+  SecurityLevel security_level = ((rand() % 2) == 0) ? kLevelDefault : kLevel3;
+  CdmResponseType status = GetUsageInfo(security_level, usage_info);
+
+  if (KEY_MESSAGE == status && !usage_info->empty())
+    return status;
+
+  security_level = (kLevel3 == security_level) ? kLevelDefault : kLevel3;
+  status = GetUsageInfo(security_level, usage_info);
+  if (NEED_PROVISIONING == status)
+    return NO_ERROR;  // Valid scenario that one of the security
+                      // levels has not been provisioned
+  return status;
+}
+
+CdmResponseType CdmEngine::GetUsageInfo(
+    SecurityLevel requested_security_level,
+    CdmUsageInfo* usage_info) {
+  if (NULL == usage_property_set_.get()) {
+    usage_property_set_.reset(new UsagePropertySet());
+  }
+  usage_property_set_->set_security_level(requested_security_level);
+
+  usage_session_.reset(new CdmSession(usage_property_set_.get()));
 
   CdmResponseType status = usage_session_->Init();
   if (NO_ERROR != status) {
@@ -573,7 +634,7 @@ CdmResponseType CdmEngine::GetUsageInfo(CdmUsageInfo* usage_info) {
 
   uint32_t index = rand() % license_info.size();
   status = usage_session_->RestoreUsageSession(license_info[index].first,
-                                                license_info[index].second);
+                                               license_info[index].second);
   if (KEY_ADDED != status) {
     LOGE("CdmEngine::GetUsageInfo: restore usage session (%u) error %d",
          index, status);
@@ -600,6 +661,7 @@ CdmResponseType CdmEngine::ReleaseUsageInfo(
   }
 
   CdmResponseType status = usage_session_->ReleaseKey(message);
+  usage_session_.reset(NULL);
   if (NO_ERROR != status) {
     LOGE("CdmEngine::ReleaseUsageInfo: release key error: %d", status);
   }
@@ -724,29 +786,44 @@ bool CdmEngine::ValidateKeySystem(const CdmKeySystem& key_system) {
 void CdmEngine::OnTimerEvent() {
   Clock clock;
   uint64_t current_time = clock.GetCurrentTime();
-  bool update_usage_information = false;
+  bool usage_update_period_expired = false;
 
-  if (current_time - last_usage_information_update_time >
+  if (current_time - last_usage_information_update_time_ >
       kUpdateUsageInformationPeriod) {
-    update_usage_information = true;
-    last_usage_information_update_time = current_time;
+    usage_update_period_expired = true;
+    last_usage_information_update_time_ = current_time;
   }
 
+  bool is_initial_usage_update = false;
+  bool is_usage_update_needed = false;
+
   for (CdmSessionMap::iterator iter = sessions_.begin();
       iter != sessions_.end(); ++iter) {
-    iter->second->OnTimerEvent(update_usage_information);
+    is_initial_usage_update = is_initial_usage_update ||
+        iter->second->is_initial_usage_update();
+    is_usage_update_needed = is_usage_update_needed ||
+        iter->second->is_usage_update_needed();
 
-    if (update_usage_information && iter->second->is_usage_update_needed()) {
-      // usage is updated for all sessions so this needs to be
-      // called only once per update usage information period
-      CdmResponseType status = iter->second->UpdateUsageInformation();
-      if (NO_ERROR != status) {
-        LOGW("Update usage information failed: %d", status);
-      } else {
-        update_usage_information = false;
+    iter->second->OnTimerEvent(usage_update_period_expired);
+  }
+
+  if (is_usage_update_needed &&
+      (usage_update_period_expired || is_initial_usage_update)) {
+    bool has_usage_been_updated = false;
+    for (CdmSessionMap::iterator iter = sessions_.begin();
+        iter != sessions_.end(); ++iter) {
+      iter->second->reset_usage_flags();
+      if (!has_usage_been_updated) {
+        // usage is updated for all sessions so this needs to be
+        // called only once per update usage information period
+        CdmResponseType status = iter->second->UpdateUsageInformation();
+        if (NO_ERROR != status) {
+          LOGW("Update usage information failed: %d", status);
+        } else {
+          has_usage_been_updated = true;
+        }
       }
     }
-    iter->second->reset_is_usage_update_needed();
   }
 }
 

libwvdrmengine/cdm/core/src/cdm_session.cpp

@@ -72,6 +72,7 @@ void CdmSession::Create(
   license_received_ = false;
   is_offline_ = false;
   is_release_ = false;
+  is_initial_usage_update_ = true;
   is_usage_update_needed_ = false;
   is_initial_decryption_ = true;
   has_decrypted_recently_ = false;
@@ -152,11 +153,18 @@ CdmResponseType CdmSession::RestoreOfflineSession(
     return UNKNOWN_ERROR;
   }
 
-  if (!license_parser_->RestoreOfflineLicense(key_request_, key_response_,
-                                              offline_key_renewal_response_,
-                                              playback_start_time,
-                                              last_playback_time)) {
-    return UNKNOWN_ERROR;
+  if (license_type == kLicenseTypeRelease) {
+    if (!license_parser_->RestoreLicenseForRelease(key_request_,
+                                                   key_response_)) {
+      return UNKNOWN_ERROR;
+    }
+  } else {
+    if (!license_parser_->RestoreOfflineLicense(key_request_, key_response_,
+                                                offline_key_renewal_response_,
+                                                playback_start_time,
+                                                last_playback_time)) {
+      return UNKNOWN_ERROR;
+    }
   }
 
   license_received_ = true;
@@ -172,7 +180,7 @@ CdmResponseType CdmSession::RestoreUsageSession(
   key_request_ = key_request;
   key_response_ = key_response;
 
-  if (!license_parser_->RestoreUsageLicense(key_request_, key_response_)) {
+  if (!license_parser_->RestoreLicenseForRelease(key_request_, key_response_)) {
     return UNKNOWN_ERROR;
   }
 

libwvdrmengine/cdm/core/src/crypto_session.cpp

@@ -421,10 +421,19 @@ CdmResponseType CryptoSession::LoadKeys(
       provider_session_token.length());
 
   if (OEMCrypto_SUCCESS == sts) {
+    if (!provider_session_token.empty()) {
+      sts = OEMCrypto_UpdateUsageTable();
+      if (sts != OEMCrypto_SUCCESS) {
+        LOGW("CryptoSession::LoadKeys: OEMCrypto_UpdateUsageTable error=%ld",
+            sts);
+      }
+    }
     return KEY_ADDED;
   } else if (OEMCrypto_ERROR_TOO_MANY_KEYS == sts) {
+    LOGE("CryptoSession::LoadKeys: OEMCrypto_LoadKeys error=%d", sts);
     return INSUFFICIENT_CRYPTO_RESOURCES;
   } else {
+    LOGE("CryptoSession::LoadKeys: OEMCrypto_LoadKeys error=%d", sts);
     return KEY_ERROR;
   }
 }
@@ -439,7 +448,7 @@ bool CryptoSession::LoadCertificatePrivateKey(std::string& wrapped_key) {
       wrapped_key.size());
 
   if (OEMCrypto_SUCCESS != sts) {
-    LOGD("LoadCertificatePrivateKey: OEMCrypto_LoadDeviceRSAKey error=%d", sts);
+    LOGE("LoadCertificatePrivateKey: OEMCrypto_LoadDeviceRSAKey error=%d", sts);
     return false;
   }
 
@@ -509,7 +518,7 @@ bool CryptoSession::GenerateDerivedKeys(const std::string& message) {
       enc_deriv_message.size());
 
   if (OEMCrypto_SUCCESS != sts) {
-    LOGD("GenerateDerivedKeys: OEMCrypto_GenerateDerivedKeys error=%d", sts);
+    LOGE("GenerateDerivedKeys: OEMCrypto_GenerateDerivedKeys error=%d", sts);
     return false;
   }
 
@@ -533,7 +542,7 @@ bool CryptoSession::GenerateDerivedKeys(const std::string& message,
       enc_deriv_message.size());
 
   if (OEMCrypto_SUCCESS != sts) {
-    LOGD("GenerateDerivedKeys: OEMCrypto_DeriveKeysFromSessionKey err=%d", sts);
+    LOGE("GenerateDerivedKeys: OEMCrypto_DeriveKeysFromSessionKey err=%d", sts);
     return false;
   }
 
@@ -554,7 +563,7 @@ bool CryptoSession::GenerateSignature(const std::string& message,
 
   if (OEMCrypto_SUCCESS != sts) {
     if (OEMCrypto_ERROR_SHORT_BUFFER != sts) {
-      LOGD("GenerateSignature: OEMCrypto_GenerateSignature err=%d", sts);
+      LOGE("GenerateSignature: OEMCrypto_GenerateSignature err=%d", sts);
       return false;
     }
 
@@ -567,7 +576,7 @@ bool CryptoSession::GenerateSignature(const std::string& message,
         &length);
 
     if (OEMCrypto_SUCCESS != sts) {
-      LOGD("GenerateSignature: OEMCrypto_GenerateSignature err=%d", sts);
+      LOGE("GenerateSignature: OEMCrypto_GenerateSignature err=%d", sts);
       return false;
     }
   }
@@ -593,7 +602,7 @@ bool CryptoSession::GenerateRsaSignature(const std::string& message,
 
   if (OEMCrypto_SUCCESS != sts) {
     if (OEMCrypto_ERROR_SHORT_BUFFER != sts) {
-      LOGD("GenerateRsaSignature: OEMCrypto_GenerateRSASignature err=%d", sts);
+      LOGE("GenerateRsaSignature: OEMCrypto_GenerateRSASignature err=%d", sts);
       return false;
     }
 
@@ -606,7 +615,7 @@ bool CryptoSession::GenerateRsaSignature(const std::string& message,
         &length, kSign_RSASSA_PSS);
 
     if (OEMCrypto_SUCCESS != sts) {
-      LOGD("GenerateRsaSignature: OEMCrypto_GenerateRSASignature err=%d", sts);
+      LOGE("GenerateRsaSignature: OEMCrypto_GenerateRSASignature err=%d", sts);
       return false;
     }
   }
@@ -774,10 +783,32 @@ CdmResponseType CryptoSession::GenerateUsageReport(
     *usage_duration_status = kUsageDurationPlaybackNotBegun;
     return NO_ERROR;
   }
+  LOGV("OEMCrypto_PST_Report.status: %d\n", pst_report.status);
+  LOGV("OEMCrypto_PST_Report.clock_security_level: %d\n",
+      pst_report.clock_security_level);
+  LOGV("OEMCrypto_PST_Report.pst_length: %d\n", pst_report.pst_length);
+  LOGV("OEMCrypto_PST_Report.padding: %d\n", pst_report.padding);
+  LOGV("OEMCrypto_PST_Report.seconds_since_license_received: %lld\n",
+      ntohll64(pst_report.seconds_since_license_received));
+  LOGV("OEMCrypto_PST_Report.seconds_since_first_decrypt: %lld\n",
+      ntohll64(pst_report.seconds_since_first_decrypt));
+  LOGV("OEMCrypto_PST_Report.seconds_since_last_decrypt: %lld\n",
+      ntohll64(pst_report.seconds_since_last_decrypt));
+  LOGV("OEMCrypto_PST_Report: %s\n", b2a_hex(*usage_report).c_str());
+
+  // When usage report state is inactive, we have to deduce whether the
+  // license was ever used.
+  if (kInactive == pst_report.status &&
+      (0 > ntohll64(pst_report.seconds_since_first_decrypt) ||
+       ntohll64(pst_report.seconds_since_license_received) <
+           ntohll64(pst_report.seconds_since_first_decrypt))) {
+    *usage_duration_status = kUsageDurationPlaybackNotBegun;
+    return NO_ERROR;
+  }
 
   *usage_duration_status = kUsageDurationsValid;
-  *seconds_since_started = pst_report.seconds_since_first_decrypt;
-  *seconds_since_last_played = pst_report.seconds_since_last_decrypt;
+  *seconds_since_started = ntohll64(pst_report.seconds_since_first_decrypt);
+  *seconds_since_last_played = ntohll64(pst_report.seconds_since_last_decrypt);
   return NO_ERROR;
 }
 
@@ -799,6 +830,31 @@ CdmResponseType CryptoSession::ReleaseUsageInformation(
          status);
     return UNKNOWN_ERROR;
   }
+  status = OEMCrypto_UpdateUsageTable();
+  if (status != OEMCrypto_SUCCESS) {
+    LOGW("CryptoSession::ReleaseUsageInformation: OEMCrypto_UpdateUsageTable: "
+        "error=%ld",
+        status);
+  }
+
+  return NO_ERROR;
+}
+
+CdmResponseType CryptoSession::DeleteAllUsageReports() {
+  LOGV("DeleteAllUsageReports");
+  OEMCryptoResult status = OEMCrypto_DeleteUsageTable();
+
+  if (OEMCrypto_SUCCESS != status) {
+    LOGE("CryptoSession::DeleteAllUsageReports: Delete Usage Table error =%ld",
+         status);
+  }
+
+  status = OEMCrypto_UpdateUsageTable();
+  if (status != OEMCrypto_SUCCESS) {
+    LOGE("CryptoSession::ReleaseUsageInformation: OEMCrypto_UpdateUsageTable: "
+        "error=%ld",
+        status);
+  }
 
   return NO_ERROR;
 }
@@ -840,7 +896,7 @@ bool CryptoSession::RewrapDeviceRSAKey(const std::string& message,
                                        const std::string& enc_rsa_key,
                                        const std::string& rsa_key_iv,
                                        std::string* wrapped_rsa_key) {
-  LOGD("CryptoSession::RewrapDeviceRSAKey, session id=%ld",
+  LOGV("CryptoSession::RewrapDeviceRSAKey, session id=%ld",
        static_cast<uint32_t>(oec_session_id_));
 
   const uint8_t* signed_msg = reinterpret_cast<const uint8_t*>(message.data());

libwvdrmengine/cdm/core/src/license.cpp

@@ -755,7 +755,6 @@ bool CdmLicense::RestoreOfflineLicense(
     const CdmKeyResponse& license_renewal_response,
     int64_t playback_start_time,
     int64_t last_playback_time) {
-
   if (license_request.empty() || license_response.empty()) {
     LOGE(
         "CdmLicense::RestoreOfflineLicense: key_request or response empty: "
@@ -827,26 +826,28 @@ bool CdmLicense::RestoreOfflineLicense(
   return true;
 }
 
-bool CdmLicense::RestoreUsageLicense(const CdmKeyMessage& license_request,
-                                     const CdmKeyResponse& license_response) {
+bool CdmLicense::RestoreLicenseForRelease(
+    const CdmKeyMessage& license_request,
+    const CdmKeyResponse& license_response) {
 
   if (license_request.empty() || license_response.empty()) {
     LOGE(
-        "CdmLicense::RestoreUsageLicense: key_request or response empty: %u %u",
+        "CdmLicense::RestoreLicenseForRelease: key_request or response empty:"
+        " %u %u",
         license_request.size(), license_response.size());
     return false;
   }
 
   SignedMessage signed_request;
   if (!signed_request.ParseFromString(license_request)) {
-    LOGE("CdmLicense::RestoreUsageLicense: license_request parse failed");
+    LOGE("CdmLicense::RestoreLicenseForRelease: license_request parse failed");
     return false;
   }
 
   if (signed_request.type() != SignedMessage::LICENSE_REQUEST) {
     LOGE(
-        "CdmLicense::RestoreUsageLicense: license request type: expected = %d,"
-        " actual = %d",
+        "CdmLicense::RestoreLicenseForRelease: license request type: expected "
+        "= %d, actual = %d",
         SignedMessage::LICENSE_REQUEST, signed_request.type());
     return false;
   }
@@ -855,20 +856,21 @@ bool CdmLicense::RestoreUsageLicense(const CdmKeyMessage& license_request,
 
   SignedMessage signed_response;
   if (!signed_response.ParseFromString(license_response)) {
-    LOGE("CdmLicense::RestoreUsageLicense: unable to parse signed license"
+    LOGE("CdmLicense::RestoreLicenseForRelease: unable to parse signed license"
         " response");
     return false;
   }
 
   if (SignedMessage::LICENSE != signed_response.type()) {
-    LOGE("CdmLicense::RestoreUsageLicense: unrecognized signed message type: %d"
+    LOGE("CdmLicense::RestoreLicenseForRelease: unrecognized signed message "
+         "type: %d"
         , signed_response.type());
     return false;
   }
 
   if (Properties::use_certificates_as_identification()) {
     if (!signed_response.has_session_key()) {
-      LOGE("CdmLicense::RestoreUsageLicense: no session keys present");
+      LOGE("CdmLicense::RestoreLicenseForRelease: no session keys present");
       return false;
     }
 
@@ -880,16 +882,24 @@ bool CdmLicense::RestoreUsageLicense(const CdmKeyMessage& license_request,
   }
 
   if (!signed_response.has_signature()) {
-    LOGE("CdmLicense::RestoreUsageLicense: license response is not signed");
+    LOGE("CdmLicense::RestoreLicenseForRelease: license response is not"
+        " signed");
     return false;
   }
 
   License license;
   if (!license.ParseFromString(signed_response.msg())) {
-    LOGE("CdmLicense::RestoreUsageLicense: unable to parse license response");
+    LOGE("CdmLicense::RestoreLicenseForRelease: unable to parse license"
+        " response");
     return false;
   }
 
+  if (license.id().has_provider_session_token())
+    provider_session_token_ = license.id().provider_session_token();
+
+  if (license.policy().has_renewal_server_url())
+    server_url_ = license.policy().renewal_server_url();
+
   policy_engine_->SetLicense(license);
   return true;
 }

libwvdrmengine/cdm/core/src/string_conversions.cpp

@@ -174,14 +174,31 @@ int64_t htonll64(int64_t x) {  // Convert to big endian (network-byte-order)
     int64_t number;
   } mixed;
   mixed.number = 1;
-  if (mixed.array[0] == 1) {
-    mixed.number = x;  // Little Endian.
+  if (mixed.array[0] == 1) {  // Little Endian.
+    mixed.number = x;
     uint32_t temp = mixed.array[0];
     mixed.array[0] = htonl(mixed.array[1]);
     mixed.array[1] = htonl(temp);
     return mixed.number;
-  } else {
-    return x;  // Big Endian.
+  } else {  // Big Endian.
+    return x;
+  }
+}
+
+int64_t ntohll64(int64_t x) {  // Convert from big endian (network-byte-order)
+  union {
+    uint32_t array[2];
+    int64_t number;
+  } mixed;
+  mixed.number = 1;
+  if (mixed.array[0] == 1) {  // Little Endian.
+    mixed.number = x;
+    uint32_t temp = mixed.array[0];
+    mixed.array[0] = ntohl(mixed.array[1]);
+    mixed.array[1] = ntohl(temp);
+    return mixed.number;
+  } else {  // Big Endian.
+    return x;
   }
 }