Clean up other core CDM logs.

[ Merge of http://go/wvgerrit/122613 ]

Further log clean up in the core CDM code.
- Changed several INFO logs to DEBUG and VERBOSE
- Added more identifiers to the DEBUG logs to help match resource
  associations
- Added more enum-to-string functions
- Unknown enum values will be formatted to contain their numeric
  value

Key areas improved are the UsageTableHeader and CdmSession.

Bug: 183576879
Test: CE CDM unittests
Change-Id: I2d11e714d419e0736d3e2f7a7668e8d36d7ef449
This commit is contained in:
Alex Dale
2021-04-19 19:27:40 -07:00
parent 85afe8c0b0
commit 0579fe805e
7 changed files with 338 additions and 200 deletions

View File

@@ -275,8 +275,9 @@ CdmResponseType CdmSession::RestoreOfflineSession(const CdmKeySetId& key_set_id,
if (!file_handle_->RetrieveLicense(key_set_id, &license_data,
&sub_error_code)) {
LOGE("Failed to retrieve license: sub_error_code = %d, key_set_id = %s",
static_cast<int>(sub_error_code), key_set_id.c_str());
LOGE("Failed to retrieve license: sub_error_code = %s, key_set_id = %s",
DeviceFiles::ResponseTypeToString(sub_error_code),
IdToString(key_set_id));
SetErrorDetail(error_detail, sub_error_code);
return sub_error_code == DeviceFiles::kFileNotFound ? KEYSET_ID_NOT_FOUND_4
: GET_LICENSE_ERROR;
@@ -308,8 +309,9 @@ CdmResponseType CdmSession::RestoreOfflineSession(const CdmKeySetId& key_set_id,
// retry.
if (!(license_type == kLicenseTypeRelease ||
license_data.state == kLicenseStateActive)) {
LOGE("Invalid offline license state: state = %d, license_type = %d",
static_cast<int>(license_data.state), static_cast<int>(license_type));
LOGE("Invalid offline license state: state = %s, license_type = %s",
CdmOfflineLicenseStateToString(license_data.state),
CdmLicenseTypeToString(license_type));
return GET_RELEASED_LICENSE_ERROR;
}
@@ -502,7 +504,8 @@ CdmResponseType CdmSession::GenerateKeyRequestInternal(
if (is_release_) {
return GenerateReleaseRequest(key_request);
} else if (license_received_) {
}
if (license_received_) {
// A call to GenerateKeyRequest after the initial license has been received
// is either a renewal/release request or a key rotation event
if (init_data.contains_entitled_keys()) {
@@ -510,41 +513,40 @@ CdmResponseType CdmSession::GenerateKeyRequestInternal(
key_request->type = kKeyRequestTypeNone;
key_request->url.clear();
return license_parser_->HandleEmbeddedKeyData(init_data);
} else {
return GenerateRenewalRequest(key_request);
}
} else {
key_request->type = kKeyRequestTypeInitial;
if (!init_data.is_supported()) {
LOGW("Unsupported init data type: %s", init_data.type().c_str());
return UNSUPPORTED_INIT_DATA;
}
if (init_data.IsEmpty() && !license_parser_->HasInitData()) {
LOGW("Init data absent");
return INIT_DATA_NOT_FOUND;
}
if (is_offline_ && key_set_id_.empty()) {
LOGE("Unable to generate key set ID");
return KEY_REQUEST_ERROR_1;
}
CdmResponseType status = LoadPrivateKey();
if (status != NO_ERROR) return status;
app_parameters_ = app_parameters;
status = license_parser_->PrepareKeyRequest(
init_data, drm_certificate_, license_type, app_parameters,
&key_request->message, &key_request->url);
if (status != KEY_MESSAGE) return status;
key_request_ = key_request->message;
if (is_offline_) {
offline_init_data_ = init_data.data();
offline_release_server_url_ = key_request->url;
}
return KEY_MESSAGE;
return GenerateRenewalRequest(key_request);
}
// Otherwise, initialize license request.
key_request->type = kKeyRequestTypeInitial;
if (!init_data.is_supported()) {
LOGW("Unsupported init data type: %s", init_data.type().c_str());
return UNSUPPORTED_INIT_DATA;
}
if (init_data.IsEmpty() && !license_parser_->HasInitData()) {
LOGW("Init data absent");
return INIT_DATA_NOT_FOUND;
}
if (is_offline_ && key_set_id_.empty()) {
LOGE("Key set ID not set");
return KEY_REQUEST_ERROR_1;
}
// Attempt to load provisioned private key if available.
CdmResponseType status = LoadPrivateKey();
if (status != NO_ERROR) return status;
app_parameters_ = app_parameters;
status = license_parser_->PrepareKeyRequest(
init_data, drm_certificate_, license_type, app_parameters,
&key_request->message, &key_request->url);
if (status != KEY_MESSAGE) return status;
key_request_ = key_request->message;
if (is_offline_) {
offline_init_data_ = init_data.data();
offline_release_server_url_ = key_request->url;
}
return KEY_MESSAGE;
}
// This thin wrapper allows us to update metrics.
@@ -562,80 +564,78 @@ CdmResponseType CdmSession::AddKeyInternal(const CdmKeyResponse& key_response) {
}
if (is_release_) {
CdmResponseType sts = ReleaseKey(key_response);
const CdmResponseType sts = ReleaseKey(key_response);
return (sts == NO_ERROR) ? KEY_ADDED : sts;
} else if (license_received_) { // renewal
}
if (license_received_) { // renewal
return RenewKey(key_response);
} else {
// If usage table header+entries are supported, preprocess the license
// to see if it has a provider session token. If so a new entry needs
// to be created.
CdmResponseType sts;
std::string provider_session_token;
if (supports_usage_info()) {
if (license_parser_->ExtractProviderSessionToken(
key_response, &provider_session_token) &&
!provider_session_token.empty()) {
std::string app_id;
GetApplicationId(&app_id);
sts = usage_table_header_->AddEntry(
crypto_session_.get(), is_offline_, key_set_id_,
DeviceFiles::GetUsageInfoFileName(app_id), key_response,
&usage_entry_number_);
crypto_metrics_->usage_table_header_add_entry_.Increment(sts);
if (sts != NO_ERROR) return sts;
}
}
sts = license_parser_->HandleKeyResponse(/* is restore */ false,
key_response);
// Update the license sdk and service versions.
const VersionInfo& version_info = license_parser_->GetServiceVersion();
metrics_->license_sdk_version_.Record(version_info.license_sdk_version());
metrics_->license_sdk_version_.Record(
version_info.license_service_version());
// Update or invalidate entry if usage table header+entries are supported
if (!provider_session_token.empty() && supports_usage_info()) {
if (sts != KEY_ADDED) {
const CdmResponseType invalidate_sts =
usage_table_header_->InvalidateEntry(
usage_entry_number_, true, file_handle_.get(), crypto_metrics_);
crypto_metrics_->usage_table_header_delete_entry_.Increment(
invalidate_sts);
if (invalidate_sts != NO_ERROR) {
LOGW("Invalidate usage entry failed: status = %d",
static_cast<int>(invalidate_sts));
}
}
}
if (sts != KEY_ADDED) return (sts == KEY_ERROR) ? ADD_KEY_ERROR : sts;
license_received_ = true;
key_response_ = key_response;
LOGV("Key added: provider_session_token = %s (size = %zu)",
license_parser_->provider_session_token().c_str(),
license_parser_->provider_session_token().size());
if ((is_offline_ || has_provider_session_token()) && !is_temporary_) {
if (has_provider_session_token() && supports_usage_info()) {
usage_table_header_->UpdateEntry(usage_entry_number_,
crypto_session_.get(), &usage_entry_);
}
if (!is_offline_)
usage_provider_session_token_ =
license_parser_->provider_session_token();
sts = StoreLicense();
}
// If usage table header+entries are supported, preprocess the license
// to see if it has a provider session token. If so a new entry needs
// to be created.
CdmResponseType sts;
std::string provider_session_token;
if (supports_usage_info()) {
if (license_parser_->ExtractProviderSessionToken(key_response,
&provider_session_token) &&
!provider_session_token.empty()) {
std::string app_id;
GetApplicationId(&app_id);
sts = usage_table_header_->AddEntry(
crypto_session_.get(), is_offline_, key_set_id_,
DeviceFiles::GetUsageInfoFileName(app_id), key_response,
&usage_entry_number_);
crypto_metrics_->usage_table_header_add_entry_.Increment(sts);
if (sts != NO_ERROR) return sts;
}
has_license_been_loaded_ = true;
return KEY_ADDED;
}
sts =
license_parser_->HandleKeyResponse(/* is restore */ false, key_response);
// Update the license sdk and service versions.
const VersionInfo& version_info = license_parser_->GetServiceVersion();
metrics_->license_sdk_version_.Record(version_info.license_sdk_version());
metrics_->license_sdk_version_.Record(version_info.license_service_version());
// Update or invalidate entry if usage table header+entries are supported
if (!provider_session_token.empty() && supports_usage_info()) {
if (sts != KEY_ADDED) {
const CdmResponseType invalidate_sts =
usage_table_header_->InvalidateEntry(
usage_entry_number_, true, file_handle_.get(), crypto_metrics_);
crypto_metrics_->usage_table_header_delete_entry_.Increment(
invalidate_sts);
if (invalidate_sts != NO_ERROR) {
LOGW("Invalidate usage entry failed: status = %d",
static_cast<int>(invalidate_sts));
}
}
}
if (sts != KEY_ADDED) return (sts == KEY_ERROR) ? ADD_KEY_ERROR : sts;
license_received_ = true;
key_response_ = key_response;
LOGV("Key added: provider_session_token = %s (size = %zu)",
IdToString(license_parser_->provider_session_token()),
license_parser_->provider_session_token().size());
if ((is_offline_ || has_provider_session_token()) && !is_temporary_) {
if (has_provider_session_token() && supports_usage_info()) {
usage_table_header_->UpdateEntry(usage_entry_number_,
crypto_session_.get(), &usage_entry_);
}
if (!is_offline_)
usage_provider_session_token_ = license_parser_->provider_session_token();
sts = StoreLicense();
if (sts != NO_ERROR) return sts;
}
has_license_been_loaded_ = true;
return KEY_ADDED;
}
CdmResponseType CdmSession::QueryStatus(CdmQueryMap* query_response) {
@@ -1289,5 +1289,4 @@ void CdmSession::set_policy_engine(PolicyEngine* policy_engine) {
void CdmSession::set_file_handle(DeviceFiles* file_handle) {
file_handle_.reset(file_handle);
}
} // namespace wvcdm