From 0579fe805ea228c29f8f393fe42e5933b86bb1e4 Mon Sep 17 00:00:00 2001 From: Alex Dale Date: Mon, 19 Apr 2021 19:27:40 -0700 Subject: [PATCH] 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 --- .../cdm/core/include/device_files.h | 6 + .../cdm/core/include/wv_cdm_types.h | 10 +- libwvdrmengine/cdm/core/src/cdm_session.cpp | 215 +++++++++--------- .../cdm/core/src/crypto_session.cpp | 33 ++- libwvdrmengine/cdm/core/src/device_files.cpp | 113 +++++++-- .../cdm/core/src/usage_table_header.cpp | 89 ++++---- libwvdrmengine/cdm/core/src/wv_cdm_types.cpp | 72 +++++- 7 files changed, 338 insertions(+), 200 deletions(-) diff --git a/libwvdrmengine/cdm/core/include/device_files.h b/libwvdrmengine/cdm/core/include/device_files.h index d4a00c54..c62001b5 100644 --- a/libwvdrmengine/cdm/core/include/device_files.h +++ b/libwvdrmengine/cdm/core/include/device_files.h @@ -66,6 +66,12 @@ class DeviceFiles { kLicenseNotPresent = kResponseTypeBase + 16, }; + // Converts the different enum types to a human readable C-string for + // logging. + static const char* CertificateStateToString(CertificateState state); + static const char* CertificateTypeToString(CertificateType type); + static const char* ResponseTypeToString(ResponseType type); + // CdmLicenseData represents all of the data that is stored in CDM // license file. License data is uniquely keyed using |key_set_id|. struct CdmLicenseData { diff --git a/libwvdrmengine/cdm/core/include/wv_cdm_types.h b/libwvdrmengine/cdm/core/include/wv_cdm_types.h index d4643ad1..08b7163c 100644 --- a/libwvdrmengine/cdm/core/include/wv_cdm_types.h +++ b/libwvdrmengine/cdm/core/include/wv_cdm_types.h @@ -798,9 +798,18 @@ class Key; // logging. Query strings values are used if available for the enum. // These functions will fail silently to avoid double logging. const char* CdmCertificateTypeToString(CdmCertificateType type); +const char* CdmClientTokenTypeToString(CdmClientTokenType type); const char* CdmLicenseTypeToString(CdmLicenseType license_type); +const char* CdmOfflineLicenseStateToString( + CdmOfflineLicenseState license_state); const char* CdmSecurityLevelToString(CdmSecurityLevel security_level); +const char* CdmUsageEntryStorageTypeToString(CdmUsageEntryStorageType type); const char* SecurityLevelToString(SecurityLevel security_level); +// Converts a generic, unknown enum value to a string representation +// containing its numeric value. +// The pointer returned from this function is thread_local. +const char* UnknownEnumValueToString(int value); + // Both IdToString() and IdPtrToString() functions are used to convert // session IDs, key set IDs or other CDM specific identifiers to a // loggable format. @@ -808,7 +817,6 @@ const char* IdToString(const std::string& id); // Some CDM API function allow for optional string parameters to be // provided as string pointers. const char* IdPtrToString(const std::string* id); - } // namespace wvcdm #endif // WVCDM_CORE_WV_CDM_TYPES_H_ diff --git a/libwvdrmengine/cdm/core/src/cdm_session.cpp b/libwvdrmengine/cdm/core/src/cdm_session.cpp index caddc805..46d54941 100644 --- a/libwvdrmengine/cdm/core/src/cdm_session.cpp +++ b/libwvdrmengine/cdm/core/src/cdm_session.cpp @@ -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(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(license_data.state), static_cast(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(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(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 diff --git a/libwvdrmengine/cdm/core/src/crypto_session.cpp b/libwvdrmengine/cdm/core/src/crypto_session.cpp index 4f0f36b4..ac39dc6f 100644 --- a/libwvdrmengine/cdm/core/src/crypto_session.cpp +++ b/libwvdrmengine/cdm/core/src/crypto_session.cpp @@ -509,8 +509,8 @@ CdmSecurityLevel CryptoSession::GetSecurityLevel( if (length != kExpectedSecurityLevelLength) { LOGE( "Unexpected security level length: " - "length = %zu, requested_security_level = %d", - length, static_cast(requested_security_level)); + "length = %zu, requested_security_level = %s", + length, SecurityLevelToString(requested_security_level)); return kSecurityLevelUnknown; } const std::string security_level(level); @@ -525,8 +525,8 @@ CdmSecurityLevel CryptoSession::GetSecurityLevel( } LOGE( "Ill-formed security level: " - "level = \"%s\", requested_security_level = %d", - security_level.c_str(), static_cast(requested_security_level)); + "level = \"%s\", requested_security_level = %s", + security_level.c_str(), SecurityLevelToString(requested_security_level)); return kSecurityLevelUnknown; } @@ -673,8 +673,8 @@ CdmResponseType CryptoSession::GetSystemIdInternal(uint32_t* system_id) { uint32_t* id = reinterpret_cast(&token[4]); *system_id = ntohl(*id); return NO_ERROR; - - } else if (pre_provision_token_type_ == kClientTokenOemCert) { + } + if (pre_provision_token_type_ == kClientTokenOemCert) { // Get the OEM Cert std::string oem_cert; CdmResponseType status = GetTokenFromOemCert(&oem_cert); @@ -685,16 +685,15 @@ CdmResponseType CryptoSession::GetSystemIdInternal(uint32_t* system_id) { return EXTRACT_SYSTEM_ID_FROM_OEM_CERT_ERROR; return NO_ERROR; - + } + if (pre_provision_token_type_ == kClientTokenDrmCert) { // TODO(blueeyes): Support loading the system id from a pre-provisioned // Drm certificate. - } else if (pre_provision_token_type_ == kClientTokenDrmCert) { return NO_ERROR; - } else { - LOGE("Unsupported pre-provision token type: %d", - static_cast(pre_provision_token_type_)); - return UNKNOWN_CLIENT_TOKEN_TYPE; } + LOGE("Unsupported pre-provision token type: %d", + static_cast(pre_provision_token_type_)); + return UNKNOWN_CLIENT_TOKEN_TYPE; } bool CryptoSession::ExtractSystemIdFromOemCert(const std::string& oem_cert, @@ -721,7 +720,8 @@ CdmResponseType CryptoSession::GetProvisioningId(std::string* provisioning_id) { } return NO_ERROR; - } else if (pre_provision_token_type_ == kClientTokenKeybox) { + } + if (pre_provision_token_type_ == kClientTokenKeybox) { std::string token; CdmResponseType status = GetTokenFromKeybox(&token); @@ -734,11 +734,10 @@ CdmResponseType CryptoSession::GetProvisioningId(std::string* provisioning_id) { provisioning_id->assign(reinterpret_cast(&token[8]), 16); return NO_ERROR; - } else { - LOGE("Unsupported pre-provision token type: %d", - static_cast(pre_provision_token_type_)); - return UNKNOWN_CLIENT_TOKEN_TYPE; } + LOGE("Unsupported pre-provision token type: %d", + static_cast(pre_provision_token_type_)); + return UNKNOWN_CLIENT_TOKEN_TYPE; } uint8_t CryptoSession::GetSecurityPatchLevel() { diff --git a/libwvdrmengine/cdm/core/src/device_files.cpp b/libwvdrmengine/cdm/core/src/device_files.cpp index 06dab5e9..e9925da3 100644 --- a/libwvdrmengine/cdm/core/src/device_files.cpp +++ b/libwvdrmengine/cdm/core/src/device_files.cpp @@ -85,8 +85,8 @@ using video_widevine_client::sdk:: return false; \ } +namespace wvcdm { namespace { - const char kEmptyFileName[] = ""; const char kFalse[] = "false"; const char kHlsAttributesFileNameExt[] = ".hal"; @@ -100,21 +100,21 @@ constexpr int64_t kFourMonthsInSeconds = (2 * 30 + 2 * 31) * 24 * 60 * 60; // Helper methods bool SetDeviceCertificate(const std::string& certificate, - const wvcdm::CryptoWrappedKey& private_key, + const CryptoWrappedKey& private_key, DeviceCertificate* mutable_device_certificate) { RETURN_FALSE_IF_NULL(mutable_device_certificate); mutable_device_certificate->set_certificate(certificate); mutable_device_certificate->set_wrapped_private_key(private_key.key()); switch (private_key.type()) { - case wvcdm::CryptoWrappedKey::kRsa: + case CryptoWrappedKey::kRsa: mutable_device_certificate->set_key_type(DeviceCertificate::RSA); return true; - case wvcdm::CryptoWrappedKey::kEcc: + case CryptoWrappedKey::kEcc: mutable_device_certificate->set_key_type(DeviceCertificate::ECC); return true; - case wvcdm::CryptoWrappedKey::kUninitialized: // Suppress compiler - // warnings. + case CryptoWrappedKey::kUninitialized: // Suppress compiler + // warnings. default: LOGE("Unexpected key type: %d", private_key.type()); return false; @@ -123,7 +123,7 @@ bool SetDeviceCertificate(const std::string& certificate, bool ExtractFromDeviceCertificate(const DeviceCertificate& device_certificate, std::string* certificate, - wvcdm::CryptoWrappedKey* private_key) { + CryptoWrappedKey* private_key) { RETURN_FALSE_IF_NULL(certificate); RETURN_FALSE_IF_NULL(private_key); @@ -161,29 +161,29 @@ bool ExtractFromDeviceCertificate(const DeviceCertificate& device_certificate, device_certificate.key_type(); switch (key_type) { case DeviceCertificate::RSA: - private_key->set_type(wvcdm::CryptoWrappedKey::kRsa); + private_key->set_type(CryptoWrappedKey::kRsa); break; case DeviceCertificate::ECC: - private_key->set_type(wvcdm::CryptoWrappedKey::kEcc); + private_key->set_type(CryptoWrappedKey::kEcc); break; default: LOGW("Unknown DRM key type, defaulting to RSA: type = %d", key_type); - private_key->set_type(wvcdm::CryptoWrappedKey::kRsa); + private_key->set_type(CryptoWrappedKey::kRsa); break; } } else { // Possible that device certificate is from V15, in this case, the // only supported key of at that time was RSA. LOGD("No key type info, assuming RSA"); - private_key->set_type(wvcdm::CryptoWrappedKey::kRsa); + private_key->set_type(CryptoWrappedKey::kRsa); } return true; } -bool FindOrInsertUsageCertificate( - const std::string& drm_certificate, - const wvcdm::CryptoWrappedKey& wrapped_private_key, UsageInfo* usage_info, - uint32_t* drm_certificate_id) { +bool FindOrInsertUsageCertificate(const std::string& drm_certificate, + const CryptoWrappedKey& wrapped_private_key, + UsageInfo* usage_info, + uint32_t* drm_certificate_id) { RETURN_FALSE_IF_NULL(usage_info); RETURN_FALSE_IF_NULL(drm_certificate_id); @@ -228,8 +228,7 @@ bool FindUsageCertificate( uint32_t drm_certificate_id, const google::protobuf::RepeatedPtrField& drm_certificate_cache, - std::string* drm_certificate, - wvcdm::CryptoWrappedKey* wrapped_private_key) { + std::string* drm_certificate, CryptoWrappedKey* wrapped_private_key) { for (const UsageInfo_DrmUsageCertificate& drm_usage_cert : drm_certificate_cache) { if (drm_usage_cert.drm_certificate_id() == drm_certificate_id) { @@ -285,10 +284,80 @@ bool UsageCertificateCacheCleanUp(UsageInfo* usage_info) { return true; } - } // namespace -namespace wvcdm { +// static +const char* DeviceFiles::CertificateStateToString(CertificateState state) { + switch (state) { + case kCertificateValid: + return "Valid"; + case kCertificateExpired: + return "Expired"; + case kCertificateNotFound: + return "NotFound"; + case kCertificateInvalid: + return "Invalid"; + case kCannotHandle: + return "CannotHandle"; + } + return UnknownEnumValueToString(static_cast(state)); +} + +// static +const char* DeviceFiles::CertificateTypeToString(CertificateType type) { + switch (type) { + case kCertificateDefault: + return "Default"; + case kCertificateLegacy: + return "Legacy"; + case kCertificateAtsc: + return "ATSC"; + } + return UnknownEnumValueToString(static_cast(type)); +} + +// static +const char* DeviceFiles::ResponseTypeToString(ResponseType type) { + switch (type) { + case kNoError: + return "NoError"; + case kObjectNotInitialized: + return "ObjectNotInitialized"; + case kParameterNull: + return "ParameterNull"; + case kBasePathUnavailable: + return "PathUnavailable"; + case kFileNotFound: + return "NotFound"; + case kFileOpenFailed: + return "OpenFailed"; + case kFileWriteError: + return "WriteError"; + case kFileReadError: + return "ReadError"; + case kInvalidFileSize: + return "InvalidFileSize"; + case kHashComputationFailed: + return "HashFailed"; + case kFileHashMismatch: + return "HashMismatch"; + case kFileParseError1: + return "ParseHashedFileError"; + case kFileParseError2: + return "ParseFileError"; + case kUnknownLicenseState: + return "UnknownLicenseState"; + case kIncorrectFileType: + return "IncorrectFileType"; + case kIncorrectFileVersion: + return "IncorrectFileVersion"; + case kLicenseNotPresent: + return "LicenseNotFound"; + case kResponseTypeBase: // Not a valid value. + break; + } + return UnknownEnumValueToString(static_cast(type)); +} // static std::set DeviceFiles::reserved_license_ids_; @@ -671,8 +740,8 @@ bool DeviceFiles::RetrieveLicense(const std::string& key_set_id, video_widevine_client::sdk::File file; *result = RetrieveHashedFile(key_set_id + kLicenseFileNameExt, &file); if (*result != kNoError) { - LOGE("Unable to retrieve key set license file: result = %d", - static_cast(*result)); + LOGE("Unable to retrieve key set license file: result = %s", + ResponseTypeToString(*result)); return false; } @@ -1771,7 +1840,7 @@ std::string DeviceFiles::GetUsageInfoFileName(const std::string& app_id) { } std::string DeviceFiles::GetFileNameSafeHash(const std::string& input) { - return wvcdm::Base64SafeEncode(Md5Hash(input)); + return Base64SafeEncode(Md5Hash(input)); } } // namespace wvcdm diff --git a/libwvdrmengine/cdm/core/src/usage_table_header.cpp b/libwvdrmengine/cdm/core/src/usage_table_header.cpp index 98e5c9bc..919c0ea5 100644 --- a/libwvdrmengine/cdm/core/src/usage_table_header.cpp +++ b/libwvdrmengine/cdm/core/src/usage_table_header.cpp @@ -14,7 +14,6 @@ #include "wv_cdm_constants.h" namespace wvcdm { - namespace { std::string kEmptyString; wvcdm::CdmKeySetId kDummyKeySetId = "DummyKsid"; @@ -89,8 +88,8 @@ bool RetrieveOfflineLicense(DeviceFiles* device_files, DeviceFiles::CdmLicenseData license_data; DeviceFiles::ResponseType result = DeviceFiles::kNoError; if (!device_files->RetrieveLicense(key_set_id, &license_data, &result)) { - LOGW("Failed to retrieve license: key_set_id = %s, result = %d", - key_set_id.c_str(), static_cast(result)); + LOGW("Failed to retrieve license: key_set_id = %s, result = %s", + IdToString(key_set_id), DeviceFiles::ResponseTypeToString(result)); return false; } *license_message = std::move(license_data.license); @@ -127,7 +126,7 @@ bool RetrieveUsageInfoLicense(DeviceFiles* device_files, LOGW( "Failed to retrieve usage information: " "key_set_id = %s, usage_info_file_name = %s", - key_set_id.c_str(), usage_info_file_name.c_str()); + IdToString(key_set_id), IdToString(usage_info_file_name)); return false; } return true; @@ -155,8 +154,7 @@ UsageTableHeader::UsageTableHeader() bool UsageTableHeader::Init(CdmSecurityLevel security_level, CryptoSession* crypto_session) { - LOGI("Initializing usage table header: security_level = %d", - static_cast(security_level)); + LOGD("security_level = %s", CdmSecurityLevelToString(security_level)); if (crypto_session == nullptr) { LOGE("No crypto session provided"); return false; @@ -184,8 +182,8 @@ bool UsageTableHeader::Init(CdmSecurityLevel security_level, kMinimumUsageTableEntriesSupported); potential_table_capacity_ = kMinimumUsageTableEntriesSupported; } else if (potential_table_capacity_ == 0) { - LOGD("Usage table capacity is unlimited: security_level = %d", - static_cast(security_level)); + LOGD("Usage table capacity is unlimited: security_level = %s", + CdmSecurityLevelToString(security_level)); } else if (potential_table_capacity_ < kMinimumUsageTableEntriesSupported) { LOGW( "Reported usage table capacity is smaller than minimally required: " @@ -193,8 +191,8 @@ bool UsageTableHeader::Init(CdmSecurityLevel security_level, potential_table_capacity_, kMinimumUsageTableEntriesSupported); potential_table_capacity_ = kMinimumUsageTableEntriesSupported; } else { - LOGD("Usage table capacity: %zu, security_level = %d", - potential_table_capacity_, static_cast(security_level)); + LOGD("Usage table capacity: %zu, security_level = %s", + potential_table_capacity_, CdmSecurityLevelToString(security_level)); } if (!device_files_->Init(security_level)) { @@ -278,16 +276,17 @@ bool UsageTableHeader::Init(CdmSecurityLevel security_level, if (result != NO_ERROR) { LOGE( "Unable to create/delete new entry, clearing usage entries: " - "security_level = %d, usage_entry_count = %zu", - static_cast(security_level), usage_entry_info_.size()); + "security_level = %s, usage_entry_count = %zu", + CdmSecurityLevelToString(security_level), + usage_entry_info_.size()); status = result; } } } if (status != NO_ERROR || !lru_success) { - LOGE("Failed to load usage table: security_level = %d, status = %d", - static_cast(security_level), static_cast(status)); + LOGE("Failed to load usage table: security_level = %s, status = %d", + CdmSecurityLevelToString(security_level), static_cast(status)); device_files_->DeleteAllLicenses(); device_files_->DeleteAllUsageInfo(); device_files_->DeleteUsageTableInfo(); @@ -313,7 +312,10 @@ CdmResponseType UsageTableHeader::AddEntry( CryptoSession* crypto_session, bool persistent_license, const CdmKeySetId& key_set_id, const std::string& usage_info_file_name, const CdmKeyResponse& license_message, uint32_t* usage_entry_number) { - LOGI("Adding usage entry"); + LOGD("oec_session_id = %u, type = %s, current_size = %zu", + crypto_session->oec_session_id(), + persistent_license ? "OfflineLicense" : "Streaming", + usage_entry_info_.size()); metrics::CryptoMetrics* metrics = crypto_session->GetCryptoMetrics(); if (metrics == nullptr) metrics = &alternate_crypto_metrics_; @@ -331,7 +333,7 @@ CdmResponseType UsageTableHeader::AddEntry( if (status != NO_ERROR) return status; - LOGI("Locking to add entry"); + LOGV("Locking to add entry"); std::unique_lock auto_lock(usage_table_header_lock_); if (*usage_entry_number < usage_entry_info_.size()) { LOGE( @@ -402,7 +404,7 @@ CdmResponseType UsageTableHeader::LoadEntry(CryptoSession* crypto_session, const CdmUsageEntry& usage_entry, uint32_t usage_entry_number) { { - LOGI("Locking to load entry: usage_entry_number = %u", usage_entry_number); + LOGD("usage_entry_number = %u", usage_entry_number); std::unique_lock auto_lock(usage_table_header_lock_); if (usage_entry_number >= usage_entry_info_.size()) { @@ -429,7 +431,7 @@ CdmResponseType UsageTableHeader::LoadEntry(CryptoSession* crypto_session, CdmResponseType UsageTableHeader::UpdateEntry(uint32_t usage_entry_number, CryptoSession* crypto_session, CdmUsageEntry* usage_entry) { - LOGI("Locking to update entry"); + LOGD("usage_entry_number = %u", usage_entry_number); std::unique_lock auto_lock(usage_table_header_lock_); if (usage_entry_number >= usage_entry_info_.size()) { LOGE("Usage entry number %u is larger than usage entry size %zu", @@ -450,8 +452,7 @@ CdmResponseType UsageTableHeader::UpdateEntry(uint32_t usage_entry_number, CdmResponseType UsageTableHeader::InvalidateEntry( uint32_t usage_entry_number, bool defrag_table, DeviceFiles* device_files, metrics::CryptoMetrics* metrics) { - LOGI("Locking to invalidate entry: usage_entry_number = %u", - usage_entry_number); + LOGD("usage_entry_number = %u", usage_entry_number); std::unique_lock auto_lock(usage_table_header_lock_); // OEMCrypto does not have any concept of "deleting" an entry. // Instead, the CDM marks the entry's meta data as invalid (storage @@ -494,14 +495,14 @@ CdmResponseType UsageTableHeader::InvalidateEntry( } size_t UsageTableHeader::UsageInfoCount() const { - LOGI("Locking to count usage info (streaming license) entries"); + LOGV("Locking to count usage info (streaming license) entries"); std::unique_lock auto_lock(usage_table_header_lock_); return std::count_if(usage_entry_info_.cbegin(), usage_entry_info_.cend(), EntryIsUsageInfo); } size_t UsageTableHeader::OfflineEntryCount() const { - LOGI("Locking to count offline license entries"); + LOGV("Locking to count offline license entries"); std::unique_lock auto_lock(usage_table_header_lock_); return std::count_if(usage_entry_info_.cbegin(), usage_entry_info_.cend(), EntryIsOfflineLicense); @@ -511,10 +512,8 @@ CdmResponseType UsageTableHeader::MoveEntry( uint32_t from_usage_entry_number, const CdmUsageEntry& from_usage_entry, uint32_t to_usage_entry_number, DeviceFiles* device_files, metrics::CryptoMetrics* metrics) { - LOGI( - "Moving usage entry: " - "from_usage_entry_number = %u, to_usage_entry_number = %u", - from_usage_entry_number, to_usage_entry_number); + LOGD("from_usage_entry_number = %u, to_usage_entry_number = %u", + from_usage_entry_number, to_usage_entry_number); // crypto_session points to an object whose scope is this method or a test // object whose scope is the lifetime of this class @@ -574,11 +573,11 @@ CdmResponseType UsageTableHeader::MoveEntry( CdmResponseType UsageTableHeader::GetEntry(uint32_t usage_entry_number, DeviceFiles* device_files, CdmUsageEntry* usage_entry) { - LOGI("Getting usage entry: usage_entry_number = %u, storage_type: %d", - usage_entry_number, - static_cast(usage_entry_number < usage_entry_info_.size() - ? usage_entry_info_[usage_entry_number].storage_type - : kStorageTypeUnknown)); + LOGD("Getting usage_entry_number = %u, storage_type = %s", usage_entry_number, + CdmUsageEntryStorageTypeToString( + usage_entry_number < usage_entry_info_.size() + ? usage_entry_info_[usage_entry_number].storage_type + : kStorageTypeUnknown)); uint32_t entry_number; switch (usage_entry_info_[usage_entry_number].storage_type) { case kStorageLicense: { @@ -636,11 +635,11 @@ CdmResponseType UsageTableHeader::GetEntry(uint32_t usage_entry_number, CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, DeviceFiles* device_files, const CdmUsageEntry& usage_entry) { - LOGI("Storing usage entry: usage_entry_number = %u, storage type: %d", - usage_entry_number, - static_cast(usage_entry_number < usage_entry_info_.size() - ? usage_entry_info_[usage_entry_number].storage_type - : kStorageTypeUnknown)); + LOGD("usage_entry_number = %u, storage_type = %s", usage_entry_number, + CdmUsageEntryStorageTypeToString( + usage_entry_number < usage_entry_info_.size() + ? usage_entry_info_[usage_entry_number].storage_type + : kStorageTypeUnknown)); switch (usage_entry_info_[usage_entry_number].storage_type) { case kStorageLicense: { @@ -650,8 +649,8 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, if (!device_files->RetrieveLicense( usage_entry_info_[usage_entry_number].key_set_id, &license_data, &sub_error_code)) { - LOGE("Failed to retrieve license: status = %d", - static_cast(sub_error_code)); + LOGE("Failed to retrieve license: status = %s", + DeviceFiles::ResponseTypeToString(sub_error_code)); return USAGE_STORE_ENTRY_RETRIEVE_LICENSE_FAILED; } @@ -660,8 +659,8 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, license_data.usage_entry_number = usage_entry_number; if (!device_files->StoreLicense(license_data, &sub_error_code)) { - LOGE("Failed to store license: status = %d", - static_cast(sub_error_code)); + LOGE("Failed to store license: status = %s", + DeviceFiles::ResponseTypeToString(sub_error_code)); return USAGE_STORE_LICENSE_FAILED; } break; @@ -720,8 +719,8 @@ bool UsageTableHeader::StoreTable(DeviceFiles* device_files) { CdmResponseType UsageTableHeader::Shrink( metrics::CryptoMetrics* metrics, uint32_t number_of_usage_entries_to_delete) { - LOGI("Shrinking usage table: table_size = %zu, number_to_delete = %u", - usage_entry_info_.size(), number_of_usage_entries_to_delete); + LOGD("table_size = %zu, number_to_delete = %u", usage_entry_info_.size(), + number_of_usage_entries_to_delete); if (usage_entry_info_.empty()) { LOGE("Usage entry info table unexpectedly empty"); return NO_USAGE_ENTRIES; @@ -760,7 +759,7 @@ CdmResponseType UsageTableHeader::Shrink( CdmResponseType UsageTableHeader::DefragTable(DeviceFiles* device_files, metrics::CryptoMetrics* metrics) { - LOGV("Defragging table: current_size = %zu", usage_entry_info_.size()); + LOGV("current_size = %zu", usage_entry_info_.size()); // Defragging the usage table involves moving valid entries near the // end of the usage table to the position of invalid entries near the // front of the table. After the entries are moved, the CDM shrinks @@ -1013,7 +1012,7 @@ CdmResponseType UsageTableHeader::ReleaseOldestEntry( // Test only method. void UsageTableHeader::InvalidateEntryForTest(uint32_t usage_entry_number) { - LOGV("Deleting entry for test: usage_entry_number = %u", usage_entry_number); + LOGV("usage_entry_number = %u", usage_entry_number); if (usage_entry_number >= usage_entry_info_.size()) { LOGE( "Requested usage entry number is larger than table size: " @@ -1150,7 +1149,7 @@ bool UsageTableHeader::LruUpgradeAllUsageEntries() { } bool UsageTableHeader::GetRemovalCandidate(uint32_t* entry_to_remove) { - LOGI("Locking to determine removal candidates"); + LOGV("Locking to determine removal candidates"); std::unique_lock auto_lock(usage_table_header_lock_); const size_t lru_unexpired_threshold = HasUnlimitedTableCapacity() diff --git a/libwvdrmengine/cdm/core/src/wv_cdm_types.cpp b/libwvdrmengine/cdm/core/src/wv_cdm_types.cpp index ae390cfb..b3102201 100644 --- a/libwvdrmengine/cdm/core/src/wv_cdm_types.cpp +++ b/libwvdrmengine/cdm/core/src/wv_cdm_types.cpp @@ -3,13 +3,26 @@ // Agreement. #include "wv_cdm_types.h" +#include +#include + #include "wv_cdm_constants.h" namespace wvcdm { namespace { const char kEmptyIdRep[] = ""; const char kNullIdRep[] = ""; -const char kUnknownValueRep[] = ""; + +// Thread local buffer used by UnknownEnumValueToString() to represent +// unknown enum values. +thread_local char tl_unknown_rep_buf[32]; + +// Helper template function for casting enums to raw integer before +// formatting into a string representation. +template +const char* UnknownValueRep(EnumType value) { + return UnknownEnumValueToString(static_cast(value)); +} } // namespace const char* CdmCertificateTypeToString(CdmCertificateType type) { @@ -19,7 +32,21 @@ const char* CdmCertificateTypeToString(CdmCertificateType type) { case kCertificateX509: return "x509"; } - return kUnknownValueRep; + return UnknownValueRep(type); +} + +const char* CdmClientTokenTypeToString(CdmClientTokenType type) { + switch (type) { + case kClientTokenKeybox: + return "Keybox"; + case kClientTokenDrmCert: + return "DrmCert"; + case kClientTokenOemCert: + return "OemCert"; + case kClientTokenUninitialized: + return "Uninitialized"; + } + return UnknownValueRep(type); } const char* CdmLicenseTypeToString(CdmLicenseType license_type) { @@ -35,7 +62,7 @@ const char* CdmLicenseTypeToString(CdmLicenseType license_type) { case kLicenseTypeEmbeddedKeyData: return "EmbeddedKeyData"; } - return kUnknownValueRep; + return UnknownValueRep(license_type); } const char* CdmSecurityLevelToString(CdmSecurityLevel security_level) { @@ -49,9 +76,35 @@ const char* CdmSecurityLevelToString(CdmSecurityLevel security_level) { case kSecurityLevelL3: return QUERY_VALUE_SECURITY_LEVEL_L3.c_str(); case kSecurityLevelUnknown: - break; + return QUERY_VALUE_SECURITY_LEVEL_UNKNOWN.c_str(); } - return QUERY_VALUE_SECURITY_LEVEL_UNKNOWN.c_str(); + return UnknownValueRep(security_level); +} + +const char* CdmOfflineLicenseStateToString( + CdmOfflineLicenseState license_state) { + switch (license_state) { + case kLicenseStateActive: + return "Active"; + case kLicenseStateReleasing: + return "Release"; + case kLicenseStateUnknown: + return "Unknown"; + } + return UnknownValueRep(license_state); +} + +const char* CdmUsageEntryStorageTypeToString(CdmUsageEntryStorageType type) { + switch (type) { + case kStorageLicense: + return "License"; + case kStorageUsageInfo: + return "UsageInfo"; + case kStorageTypeUnknown: + // Special value used to indicate an empty entry. + return "None"; + } + return UnknownValueRep(type); } const char* SecurityLevelToString(SecurityLevel security_level) { @@ -61,7 +114,13 @@ const char* SecurityLevelToString(SecurityLevel security_level) { case kLevel3: return QUERY_VALUE_SECURITY_LEVEL_L3.c_str(); } - return kUnknownValueRep; + return UnknownValueRep(security_level); +} + +const char* UnknownEnumValueToString(int value) { + snprintf(tl_unknown_rep_buf, sizeof(tl_unknown_rep_buf), "", + value); + return tl_unknown_rep_buf; } const char* IdToString(const std::string& id) { @@ -72,5 +131,4 @@ const char* IdPtrToString(const std::string* id) { if (id == nullptr) return kNullIdRep; return id->empty() ? kEmptyIdRep : id->c_str(); } - } // namespace wvcdm