From f4360552b72f1c3f81fcd63fa8446990698d6ce8 Mon Sep 17 00:00:00 2001 From: Alex Dale Date: Thu, 1 Aug 2019 11:18:12 -0700 Subject: [PATCH] Log cleanup and reformatting for core/ (Part 2-6) [ Merge of http://go/wvgerrit/83423 ] [ Merge of http://go/wvgerrit/83424 ] [ Merge of http://go/wvgerrit/83425 ] [ Merge of http://go/wvgerrit/83426 ] [ Merge of http://go/wvgerrit/83427 ] Types of cleanup: - Removed function / class prefixes from the logs. - Fixed log string format options to match the types passed - Corrected small spelling mistakes / typos - _Tried_ to make the log format more consistent - Added static_cast conversion on enumerations when logged - Changed several LOGE to LOGW and vice versa - Used LOGE if the triggering condition stops the method/function from completing its task - Used LOGW if the triggering condition changes the expected outcome but does not stop the rest of the method/function's task - Changed several instances of `NULL` to `nullptr` - Ran clang-format on files after cleanup This is part of a larger code quality effort in Widevine DRM. Test: WV linux unittests and WV Android unit tests Bug: 134460638 Bug: 134365840 Bug: 136123217 Change-Id: I958ec70ef99eef95c38dbebd7a1acd62ef304145 --- .../cdm/core/src/cdm_session_map.cpp | 1 - .../cdm/core/src/certificate_provisioning.cpp | 61 +- .../cdm/core/src/client_identification.cpp | 31 +- .../cdm/core/src/content_key_session.cpp | 20 +- .../cdm/core/src/crypto_session.cpp | 538 ++++++++---------- libwvdrmengine/cdm/core/src/device_files.cpp | 494 +++++++--------- .../cdm/core/src/entitlement_key_session.cpp | 5 +- .../cdm/core/src/initialization_data.cpp | 166 ++---- libwvdrmengine/cdm/core/src/license.cpp | 221 +++---- .../cdm/core/src/license_key_status.cpp | 14 +- libwvdrmengine/cdm/core/src/policy_engine.cpp | 8 +- .../cdm/core/src/privacy_crypto_boringssl.cpp | 163 +++--- .../cdm/core/src/privacy_crypto_dummy.cpp | 17 +- .../cdm/core/src/service_certificate.cpp | 64 ++- .../cdm/core/src/usage_table_header.cpp | 200 ++++--- 15 files changed, 871 insertions(+), 1132 deletions(-) diff --git a/libwvdrmengine/cdm/core/src/cdm_session_map.cpp b/libwvdrmengine/cdm/core/src/cdm_session_map.cpp index c2ddad3a..3faf273f 100644 --- a/libwvdrmengine/cdm/core/src/cdm_session_map.cpp +++ b/libwvdrmengine/cdm/core/src/cdm_session_map.cpp @@ -7,7 +7,6 @@ #include #include "cdm_session.h" -#include "log.h" namespace wvcdm { diff --git a/libwvdrmengine/cdm/core/src/certificate_provisioning.cpp b/libwvdrmengine/cdm/core/src/certificate_provisioning.cpp index 019547df..512d6c93 100644 --- a/libwvdrmengine/cdm/core/src/certificate_provisioning.cpp +++ b/libwvdrmengine/cdm/core/src/certificate_provisioning.cpp @@ -68,7 +68,7 @@ void ExtractAndDecodeSignedMessage(const std::string& provisioning_response, if (start == provisioning_response.npos) { // Message is not properly wrapped - reject it. - LOGE("ExtractAndDecodeSignedMessage: cannot locate start substring"); + LOGE("Cannot locate start substring"); result->clear(); return; } else { @@ -76,7 +76,7 @@ void ExtractAndDecodeSignedMessage(const std::string& provisioning_response, size_t end = provisioning_response.find(json_end_substr, start + json_start_substr.length()); if (end == provisioning_response.npos) { - LOGE("ExtractAndDecodeSignedMessage: cannot locate end substring"); + LOGE("Cannot locate end substring"); result->clear(); return; } @@ -86,7 +86,7 @@ void ExtractAndDecodeSignedMessage(const std::string& provisioning_response, } if (message_string.empty()) { - LOGE("ExtractAndDecodeSignedMessage: CdmProvisioningResponse is empty"); + LOGE("CDM provisioning response is empty"); result->clear(); return; } @@ -127,9 +127,7 @@ CdmResponseType CertificateProvisioning::SetSpoidParameter( const std::string& origin, const std::string& spoid, ProvisioningRequest* request) { if (!request) { - LOGE( - "CertificateProvisioning::SetSpoidParameter: No request buffer " - "passed to method."); + LOGE("Output parameter |request| is not provided"); return PARAMETER_NULL; } if (!spoid.empty()) { @@ -140,8 +138,8 @@ CdmResponseType CertificateProvisioning::SetSpoidParameter( request->set_provider_id(service_certificate_->provider_id()); } else { LOGE( - "CertificateProvisioning::SetSpoidParameter: Failure getting " - "provider ID"); + "Failed to set provider ID: " + "Service certificate provider ID is empty"); return SERVICE_CERTIFICATE_PROVIDER_ID_EMPTY; } } else if (origin != EMPTY_ORIGIN) { @@ -151,9 +149,8 @@ CdmResponseType CertificateProvisioning::SetSpoidParameter( crypto_session_->GetInternalDeviceUniqueId(&device_unique_id); if (status != NO_ERROR) { - LOGE( - "CertificateProvisioning::SetSpoidParameter: Failure getting " - "device unique ID"); + LOGE("Failed to get device unique ID: status = %d", + static_cast(status)); return status; } request->set_stable_id(device_unique_id + origin); @@ -186,7 +183,7 @@ CdmResponseType CertificateProvisioning::GetProvisioningRequest( const std::string& spoid, CdmProvisioningRequest* request, std::string* default_url) { if (!default_url) { - LOGE("GetProvisioningRequest: pointer for returning URL is NULL"); + LOGE("Output parameter |default_url| is not provided"); return CERT_PROVISIONING_REQUEST_ERROR_1; } @@ -194,7 +191,8 @@ CdmResponseType CertificateProvisioning::GetProvisioningRequest( CdmResponseType status = crypto_session_->Open(requested_security_level); if (NO_ERROR != status) { - LOGE("GetProvisioningRequest: fails to create a crypto session"); + LOGE("Failed to create a crypto session: status = %d", + static_cast(status)); return status; } @@ -213,9 +211,7 @@ CdmResponseType CertificateProvisioning::GetProvisioningRequest( if (status != NO_ERROR) return status; if (!service_certificate_->has_certificate()) { - LOGE( - "CertificateProvisioning::GetProvisioningRequest: Service " - "Certificate not staged"); + LOGE("Service certificate not staged"); return CERT_PROVISIONING_EMPTY_SERVICE_CERTIFICATE; } @@ -230,7 +226,7 @@ CdmResponseType CertificateProvisioning::GetProvisioningRequest( status = crypto_session_->GenerateNonce(&nonce); if (status != NO_ERROR) { - LOGE("GetProvisioningRequest: fails to generate a nonce: %d", status); + LOGE("Failed to generate a nonce: status = %d", static_cast(status)); return status == NONCE_GENERATION_ERROR ? CERT_PROVISIONING_NONCE_GENERATION_ERROR : status; @@ -252,7 +248,7 @@ CdmResponseType CertificateProvisioning::GetProvisioningRequest( video_widevine::ProvisioningOptions_CertificateType_X509); break; default: - LOGE("GetProvisioningRequest: unknown certificate type %ld", cert_type); + LOGE("Unknown certificate type: %d", static_cast(cert_type)); return CERT_PROVISIONING_INVALID_CERT_TYPE; } @@ -271,12 +267,13 @@ CdmResponseType CertificateProvisioning::GetProvisioningRequest( &request_signature); if (status != NO_ERROR) { - LOGE("GetProvisioningRequest: fails to prepare request"); + LOGE("Failed to prepare provisioning request: status = %d", + static_cast(status)); return status; } if (request_signature.empty()) { - LOGE("GetProvisioningRequest: request signature is empty"); + LOGE("Request signature is empty"); return CERT_PROVISIONING_REQUEST_ERROR_4; } @@ -310,7 +307,7 @@ CdmResponseType CertificateProvisioning::HandleProvisioningResponse( FileSystem* file_system, const CdmProvisioningResponse& response_message, std::string* cert, std::string* wrapped_key) { if (response_message.empty()) { - LOGE("HandleProvisioningResponse: response message is empty."); + LOGE("Provisioning response message is empty"); return CERT_PROVISIONING_RESPONSE_ERROR_1; } @@ -322,9 +319,7 @@ CdmResponseType CertificateProvisioning::HandleProvisioningResponse( // Extract it and decode it. On error return an empty string. ExtractAndDecodeSignedMessage(response_message, &response); if (response.empty()) { - LOGE( - "HandleProvisioningResponse: response message is " - "an invalid JSON/base64 string."); + LOGE("Provisioning response message is an invalid JSON/base64 string"); return CERT_PROVISIONING_RESPONSE_ERROR_1; } } @@ -334,18 +329,18 @@ CdmResponseType CertificateProvisioning::HandleProvisioningResponse( // stores private device RSA key and certificate. SignedProvisioningMessage signed_response; if (!signed_response.ParseFromString(response)) { - LOGE("HandleProvisioningResponse: fails to parse signed response"); + LOGE("Failed to parse signed provisioining response"); return CERT_PROVISIONING_RESPONSE_ERROR_2; } bool error = false; if (!signed_response.has_signature()) { - LOGE("HandleProvisioningResponse: signature not found"); + LOGE("Signed response does not have signature"); error = true; } if (!signed_response.has_message()) { - LOGE("HandleProvisioningResponse: message not found"); + LOGE("Signed response does not have message"); error = true; } @@ -356,12 +351,12 @@ CdmResponseType CertificateProvisioning::HandleProvisioningResponse( ProvisioningResponse provisioning_response; if (!provisioning_response.ParseFromString(signed_message)) { - LOGE("HandleProvisioningResponse: Fails to parse signed message"); + LOGE("Failed to parse provisioning response"); return CERT_PROVISIONING_RESPONSE_ERROR_4; } if (!provisioning_response.has_device_rsa_key()) { - LOGE("HandleProvisioningResponse: key not found"); + LOGE("Provisioning response does not have RSA key"); return CERT_PROVISIONING_RESPONSE_ERROR_5; } @@ -371,7 +366,7 @@ CdmResponseType CertificateProvisioning::HandleProvisioningResponse( if (service_certificate_->VerifySignedMessage(signed_message, signature) != NO_ERROR) { // TODO(b/69562876): if the cert is bad, request a new one. - LOGE("HandleProvisioningResponse: message not properly signed"); + LOGE("Provisioning response message not properly signed"); return CERT_PROVISIONING_RESPONSE_ERROR_6; } } @@ -391,7 +386,7 @@ CdmResponseType CertificateProvisioning::HandleProvisioningResponse( &wrapped_private_key); if (status != NO_ERROR) { - LOGE("HandleProvisioningResponse: RewrapCertificate fails"); + LOGE("RewrapCertificate failed: status = %d", static_cast(status)); return status; } @@ -412,11 +407,11 @@ CdmResponseType CertificateProvisioning::HandleProvisioningResponse( DeviceFiles handle(file_system); if (!handle.Init(security_level)) { - LOGE("HandleProvisioningResponse: failed to init DeviceFiles"); + LOGE("Failed to initialize DeviceFiles"); return CERT_PROVISIONING_RESPONSE_ERROR_7; } if (!handle.StoreCertificate(device_certificate, wrapped_private_key)) { - LOGE("HandleProvisioningResponse: failed to save provisioning certificate"); + LOGE("Failed to store provisioning certificate"); return CERT_PROVISIONING_RESPONSE_ERROR_8; } diff --git a/libwvdrmengine/cdm/core/src/client_identification.cpp b/libwvdrmengine/cdm/core/src/client_identification.cpp index 30c6719c..c039a6a3 100644 --- a/libwvdrmengine/cdm/core/src/client_identification.cpp +++ b/libwvdrmengine/cdm/core/src/client_identification.cpp @@ -39,8 +39,8 @@ using video_widevine::ProvisioningResponse; using video_widevine::SignedProvisioningMessage; CdmResponseType ClientIdentification::Init(CryptoSession* crypto_session) { - if (crypto_session == NULL) { - LOGE("ClientIdentification::Init: crypto_session not provided"); + if (crypto_session == nullptr) { + LOGE("Crypto session not provided"); return PARAMETER_NULL; } @@ -52,13 +52,13 @@ CdmResponseType ClientIdentification::Init(CryptoSession* crypto_session) { CdmResponseType ClientIdentification::Init(const std::string& client_token, const std::string& device_id, CryptoSession* crypto_session) { - if (crypto_session == NULL) { - LOGE("ClientIdentification::Init: crypto_session not provided"); + if (crypto_session == nullptr) { + LOGE("Crypto session not provided"); return PARAMETER_NULL; } if (client_token.empty()) { - LOGE("ClientIdentification::Init: crypto_session not provided"); + LOGE("Client token is empty"); return PARAMETER_NULL; } @@ -84,9 +84,7 @@ CdmResponseType ClientIdentification::Prepare( } else { video_widevine::ClientIdentification::TokenType token_type; if (!GetProvisioningTokenType(&token_type)) { - LOGE( - "ClientIdentification::Prepare: failure getting provisioning token " - "type"); + LOGE("Failed to get provisioning token type"); return CLIENT_IDENTIFICATION_TOKEN_ERROR_1; } client_id->set_type(token_type); @@ -94,10 +92,8 @@ CdmResponseType ClientIdentification::Prepare( std::string token; CdmResponseType status = crypto_session_->GetProvisioningToken(&token); if (status != NO_ERROR) { - LOGE( - "ClientIdentification::Prepare: failure getting provisioning token: " - "%d", - status); + LOGE("Failed to get provisioning token: status = %d", + static_cast(status)); return status; } client_id->set_token(token); @@ -223,10 +219,8 @@ CdmResponseType ClientIdentification::Prepare( ClientIdentification_ClientCapabilities_HdcpVersion_HDCP_NO_DIGITAL_OUTPUT); break; default: - LOGW( - "ClientIdentification::PrepareClientId: unexpected HDCP max " - "capability version %d", - max_version); + LOGW("Unexpected HDCP max capability version: max_version = %d", + static_cast(max_version)); } } } @@ -304,10 +298,7 @@ bool ClientIdentification::GetProvisioningTokenType( case kClientTokenDrmCert: default: // shouldn't happen - LOGE( - "CertificateProvisioning::GetProvisioningTokenType: unexpected " - "provisioning type: %d", - token); + LOGE("Unexpected provisioning type: %d", static_cast(token)); return false; } } diff --git a/libwvdrmengine/cdm/core/src/content_key_session.cpp b/libwvdrmengine/cdm/core/src/content_key_session.cpp index 5eb010c6..2051e3df 100644 --- a/libwvdrmengine/cdm/core/src/content_key_session.cpp +++ b/libwvdrmengine/cdm/core/src/content_key_session.cpp @@ -19,7 +19,7 @@ OEMCryptoResult ContentKeySession::GenerateDerivedKeys( GenerateMacContext(message, &mac_deriv_message); GenerateEncryptContext(message, &enc_deriv_message); - LOGV("GenerateDerivedKeys: id=%ld", (uint32_t)oec_session_id_); + LOGV("Generating derived keys: id = %u", oec_session_id_); OEMCryptoResult sts; M_TIME(sts = OEMCrypto_GenerateDerivedKeys( oec_session_id_, @@ -29,7 +29,8 @@ OEMCryptoResult ContentKeySession::GenerateDerivedKeys( enc_deriv_message.size()), metrics_, oemcrypto_generate_derived_keys_, sts); if (OEMCrypto_SUCCESS != sts) { - LOGE("GenerateDerivedKeys: OEMCrypto_GenerateDerivedKeys error=%d", sts); + LOGE("OEMCrypto_GenerateDerivedKeys failed: status = %d", + static_cast(sts)); } return sts; @@ -43,7 +44,7 @@ OEMCryptoResult ContentKeySession::GenerateDerivedKeys( GenerateMacContext(message, &mac_deriv_message); GenerateEncryptContext(message, &enc_deriv_message); - LOGV("GenerateDerivedKeys: id=%ld", (uint32_t)oec_session_id_); + LOGV("Generating derived keys from session key: id = %u", oec_session_id_); OEMCryptoResult sts; M_TIME( sts = OEMCrypto_DeriveKeysFromSessionKey( @@ -56,7 +57,8 @@ OEMCryptoResult ContentKeySession::GenerateDerivedKeys( metrics_, oemcrypto_derive_keys_from_session_key_, sts); if (OEMCrypto_SUCCESS != sts) { - LOGE("GenerateDerivedKeys: OEMCrypto_DeriveKeysFromSessionKey err=%d", sts); + LOGE("OEMCrypto_DeriveKeysFromSessionKey failed: status = %d", + static_cast(sts)); } return sts; @@ -131,7 +133,7 @@ OEMCryptoResult ContentKeySession::LoadKeysAsLicenseType( GetSubstring(message, mac_key, !valid_mac_keys); OEMCrypto_Substring enc_mac_key_iv = GetSubstring(message, mac_key_iv, !valid_mac_keys); - if (!valid_mac_keys) LOGV("enc_mac_key not set"); + if (!valid_mac_keys) LOGV("|enc_mac_key| is not set"); std::vector load_keys(keys.size()); std::vector cipher_modes(keys.size()); for (size_t i = 0; i < keys.size(); ++i) { @@ -146,8 +148,10 @@ OEMCryptoResult ContentKeySession::LoadKeysAsLicenseType( ko->key_control = GetSubstring(message, ki->key_control(), !has_key_control); if (!has_key_control) { - LOGE("For key %d: XXX key has no control block. size=%d", i, - ki->key_control().length()); + LOGE( + "Crypto key does not have a control block: " + "key_index = %zu, size = %zu", + i, ki->key_control().length()); } cipher_modes[i] = ToOEMCryptoCipherMode(ki->cipher_mode()); @@ -158,7 +162,7 @@ OEMCryptoResult ContentKeySession::LoadKeysAsLicenseType( OEMCrypto_Substring pst = GetSubstring(message, provider_session_token); OEMCrypto_Substring srm_req = GetSubstring(message, srm_requirement); - LOGV("id=%ld", (uint32_t)oec_session_id_); + LOGV("session_id = %u", oec_session_id_); OEMCryptoResult sts; OEMCrypto_KeyObject* key_array_ptr = NULL; if (keys.size() > 0) key_array_ptr = &load_keys[0]; diff --git a/libwvdrmengine/cdm/core/src/crypto_session.cpp b/libwvdrmengine/cdm/core/src/crypto_session.cpp index 2e462a77..0ec821b5 100644 --- a/libwvdrmengine/cdm/core/src/crypto_session.cpp +++ b/libwvdrmengine/cdm/core/src/crypto_session.cpp @@ -25,6 +25,18 @@ #include "usage_table_header.h" #include "wv_cdm_constants.h" +#define RETURN_IF_UNINITIALIZED(ret_value) \ + if (!IsInitialized()) { \ + LOGE("Crypto session is not initialized"); \ + return ret_value; \ + } + +#define RETURN_IF_NOT_OPEN(ret_value) \ + if (!open_) { \ + LOGE("Crypto session is not open"); \ + return ret_value; \ + } + namespace { // Encode unsigned integer into a big endian formatted string @@ -63,7 +75,8 @@ std::atomic CryptoSession::request_id_index_source_(0); size_t GetOffset(std::string message, std::string field) { size_t pos = message.find(field); if (pos == std::string::npos) { - LOGE("CryptoSession::GetOffset : Cannot find offset for %s", field.c_str()); + LOGE("Cannot find the |field| offset in message: field = %s", + field.c_str()); pos = 0; } return pos; @@ -78,7 +91,8 @@ OEMCrypto_Substring GetSubstring(const std::string& message, } else { size_t pos = message.find(field); if (pos == std::string::npos) { - LOGW("GetSubstring : Cannot find offset for %s", field.c_str()); + LOGW("Cannot find the |field| substring in message: field = %s", + field.c_str()); substring.offset = 0; substring.length = 0; } else { @@ -92,7 +106,7 @@ OEMCrypto_Substring GetSubstring(const std::string& message, void GenerateMacContext(const std::string& input_context, std::string* deriv_context) { if (!deriv_context) { - LOGE("CryptoSession::GenerateMacContext : No output destination provided."); + LOGE("Output parameter |deriv_context| not provided"); return; } @@ -108,9 +122,7 @@ void GenerateMacContext(const std::string& input_context, void GenerateEncryptContext(const std::string& input_context, std::string* deriv_context) { if (!deriv_context) { - LOGE( - "CryptoSession::GenerateEncryptContext : No output destination " - "provided."); + LOGE("Output parameter |deriv_context| not provided"); return; } @@ -139,9 +151,11 @@ OEMCryptoCipherMode ToOEMCryptoCipherMode(CdmCipherMode cipher_mode) { // specified in the CryptoSession method rather than here. CdmResponseType MapOEMCryptoResult(OEMCryptoResult result, CdmResponseType default_status, - const char* error_string) { + const char* crypto_session_method) { if (result != OEMCrypto_SUCCESS) { - LOGE("%s: error %d", error_string, result); + LOGE("Mapping OEMCrypto result: crypto_session_method = %s, result = %d", + crypto_session_method ? crypto_session_method : "N/A", + static_cast(result)); } switch (result) { @@ -206,7 +220,8 @@ CdmResponseType CryptoSession::GetProvisioningMethod( break; case OEMCrypto_ProvisioningError: default: - LOGE("OEMCrypto_GetProvisioningMethod failed. %d", method); + LOGE("OEMCrypto_GetProvisioningMethod failed: method = %d", + static_cast(method)); metrics_->oemcrypto_provisioning_method_.SetError(method); return GET_PROVISIONING_METHOD_ERROR; } @@ -215,7 +230,7 @@ CdmResponseType CryptoSession::GetProvisioningMethod( } void CryptoSession::Init() { - LOGV("CryptoSession::Init"); + LOGV("Initializing crypto session"); WithStaticFieldWriteLock("Init", [&] { session_count_ += 1; if (!initialized_) { @@ -232,7 +247,7 @@ void CryptoSession::Init() { sts); }); if (OEMCrypto_SUCCESS != sts) { - LOGE("OEMCrypto_Initialize failed: %d", sts); + LOGE("OEMCrypto_Initialize failed: status = %d", static_cast(sts)); return; } initialized_ = true; @@ -241,19 +256,20 @@ void CryptoSession::Init() { } void CryptoSession::Terminate() { - LOGV("CryptoSession::Terminate"); + LOGV("Terminating crypto session"); WithStaticFieldWriteLock("Terminate", [&] { - LOGV("initialized_=%d, session_count_=%d", initialized_, session_count_); + LOGV("Terminating crypto session: initialized_ = %s, session_count_ = %d", + initialized_ ? "true" : "false", session_count_); if (session_count_ > 0) { session_count_ -= 1; } else { - LOGE("CryptoSession::Terminate error, session count: %d", session_count_); + LOGE("Invalid crypto session count: session_count_ = %d", session_count_); } if (session_count_ > 0 || !initialized_) return; OEMCryptoResult sts; WithOecWriteLock("Terminate", [&] { sts = OEMCrypto_Terminate(); }); if (OEMCrypto_SUCCESS != sts) { - LOGE("OEMCrypto_Terminate failed: %d", sts); + LOGE("OEMCrypto_Terminate failed: status = %d", static_cast(sts)); } if (usage_table_header_l1_ != NULL) { @@ -271,7 +287,7 @@ void CryptoSession::Terminate() { CdmResponseType CryptoSession::GetTokenFromKeybox(std::string* token) { if (token == nullptr) { - LOGE("CryptoSession::GetTokenFromKeybox: token not provided"); + LOGE("Output parameter |token| not provided"); return PARAMETER_NULL; } std::string temp_buffer(KEYBOX_KEY_DATA_SIZE, '\0'); @@ -296,7 +312,7 @@ CdmResponseType CryptoSession::GetTokenFromKeybox(std::string* token) { CdmResponseType CryptoSession::GetTokenFromOemCert(std::string* token) { if (token == nullptr) { - LOGE("CryptoSession::GetTokenFromOemCert: token not provided "); + LOGE("Output parameter |token| not provided"); return PARAMETER_NULL; } OEMCryptoResult status; @@ -335,7 +351,7 @@ CdmResponseType CryptoSession::GetTokenFromOemCert(std::string* token) { CdmResponseType CryptoSession::GetProvisioningToken(std::string* token) { if (token == nullptr) { - LOGE("CryptoSession::GetProvisioningToken : No token passed to method."); + LOGE("Output parameter |token| not provided"); metrics_->crypto_session_get_token_.Increment(PARAMETER_NULL); return PARAMETER_NULL; } @@ -357,21 +373,16 @@ CdmResponseType CryptoSession::GetProvisioningToken(std::string* token) { } CdmSecurityLevel CryptoSession::GetSecurityLevel() { - LOGV("CryptoSession::GetSecurityLevel"); - if (!open_) { - LOGW("CryptoSession::GetSecurityLevel: session not open"); - return kSecurityLevelUninitialized; - } + LOGV("Getting security level"); + RETURN_IF_NOT_OPEN(kSecurityLevelUninitialized); return GetSecurityLevel(requested_security_level_); } CdmSecurityLevel CryptoSession::GetSecurityLevel( SecurityLevel requested_level) { - LOGV("CryptoSession::GetSecurityLevel"); - if (!IsInitialized()) { - LOGW("Not Initialized"); - return kSecurityLevelUninitialized; - } + LOGV("Getting security level: requested_level = %d", + static_cast(requested_level)); + RETURN_IF_UNINITIALIZED(kSecurityLevelUninitialized); std::string security_level; WithOecReadLock("GetSecurityLevel", [&] { @@ -404,16 +415,10 @@ CdmSecurityLevel CryptoSession::GetSecurityLevel( CdmResponseType CryptoSession::GetInternalDeviceUniqueId( std::string* device_id) { if (device_id == nullptr) { - LOGE( - "CryptoSession::GetInternalDeviceUniqueId : No buffer passed to " - "method."); + LOGE("Output parameter |device_id| not provided"); return PARAMETER_NULL; } - - if (!IsInitialized()) { - LOGE("CryptoSession::GetInternalDeviceUniqueId: not initialized"); - return CRYPTO_SESSION_NOT_INITIALIZED; - } + RETURN_IF_UNINITIALIZED(CRYPTO_SESSION_NOT_INITIALIZED); std::vector id; size_t id_length = 32; @@ -455,8 +460,8 @@ CdmResponseType CryptoSession::GetInternalDeviceUniqueId( CdmResponseType CryptoSession::GetExternalDeviceUniqueId( std::string* device_id) { - if (device_id == NULL) { - LOGE("CryptoSession::GetExternalDeviceUniqueId: device_id not provided"); + if (device_id == nullptr) { + LOGE("Output parameter |device_id| not provided"); return PARAMETER_NULL; } std::string temp; @@ -483,26 +488,20 @@ CdmResponseType CryptoSession::GetExternalDeviceUniqueId( } bool CryptoSession::GetApiVersion(uint32_t* version) { - LOGV("CryptoSession::GetApiVersion"); - if (!open_) { - LOGW("CryptoSession::GetApiVersion: session not open"); - return false; - } + LOGV("Getting API version"); + RETURN_IF_NOT_OPEN(false); return GetApiVersion(requested_security_level_, version); } bool CryptoSession::GetApiVersion(SecurityLevel security_level, uint32_t* version) { - LOGV("CryptoSession::GetApiVersion"); + LOGV("Getting API version: security_level = %d", + static_cast(security_level)); if (!version) { - LOGE("CryptoSession::GetApiVersion: No buffer passed to method."); - return false; - } - - if (!IsInitialized()) { - LOGW("CryptoSession::GetApiVersion: not initialized"); + LOGE("Output parameter |version| not provided"); return false; } + RETURN_IF_UNINITIALIZED(false); WithOecReadLock("GetApiVersion", [&] { *version = OEMCrypto_APIVersion(security_level); }); @@ -513,11 +512,10 @@ bool CryptoSession::GetApiVersion(SecurityLevel security_level, } bool CryptoSession::GetSystemId(uint32_t* system_id) { - if (!system_id) { - LOGE("CryptoSession::GetSystemId: No buffer passed to method."); + if (system_id == nullptr) { + LOGE("Output parameter |system_id| not provided"); return false; } - if (!IsInitialized() || !open_) { return false; } @@ -530,7 +528,7 @@ bool CryptoSession::GetSystemId(uint32_t* system_id) { // call. CdmResponseType CryptoSession::GetSystemIdInternal(uint32_t* system_id) { if (system_id == nullptr) { - LOGE("CryptoSession::GetSystemIdInternal: No system_id passed to method."); + LOGE("Output parameter |system_id| not provided"); return PARAMETER_NULL; } @@ -541,8 +539,7 @@ CdmResponseType CryptoSession::GetSystemIdInternal(uint32_t* system_id) { if (status != NO_ERROR) return status; if (token.size() < 2 * sizeof(uint32_t)) { - LOGE("CryptoSession::GetSystemIdInternal: Keybox token too small: %d", - token.size()); + LOGE("Keybox token size too small: token_size = %zu", token.size()); return KEYBOX_TOKEN_TOO_SHORT; } @@ -569,10 +566,8 @@ CdmResponseType CryptoSession::GetSystemIdInternal(uint32_t* system_id) { } else if (pre_provision_token_type_ == kClientTokenDrmCert) { return NO_ERROR; } else { - LOGE( - "CryptoSession::GetSystemIdInternal: " - "Unsupported pre-provision token type %d", - pre_provision_token_type_); + LOGE("Unsupported pre-provision token type: %d", + static_cast(pre_provision_token_type_)); return UNKNOWN_CLIENT_TOKEN_TYPE; } } @@ -585,13 +580,10 @@ bool CryptoSession::ExtractSystemIdFromOemCert(const std::string& oem_cert, CdmResponseType CryptoSession::GetProvisioningId(std::string* provisioning_id) { if (provisioning_id == nullptr) { - LOGE("CryptoSession::GetProvisioningId : No buffer passed to method."); + LOGE("Output parameter |provisioning_id| not provided"); return PARAMETER_NULL; } - - if (!IsInitialized()) { - return CRYPTO_SESSION_NOT_INITIALIZED; - } + RETURN_IF_UNINITIALIZED(CRYPTO_SESSION_NOT_INITIALIZED); if (pre_provision_token_type_ == kClientTokenOemCert) { // OEM Cert devices have no provisioning-unique ID embedded in them, so we @@ -614,16 +606,15 @@ CdmResponseType CryptoSession::GetProvisioningId(std::string* provisioning_id) { if (status != NO_ERROR) return status; if (token.size() < 24) { - LOGE("CryptoSession::GetProvisioningId: token size too small: %d", - token.size()); + LOGE("Keybox token size too small: %zu", token.size()); return KEYBOX_TOKEN_TOO_SHORT; } provisioning_id->assign(reinterpret_cast(&token[8]), 16); return NO_ERROR; } else { - LOGE("CryptoSession::GetProvisioningId: unsupported token type: %d", - pre_provision_token_type_); + LOGE("Unsupported pre-provision token type: %d", + static_cast(pre_provision_token_type_)); return UNKNOWN_CLIENT_TOKEN_TYPE; } } @@ -638,11 +629,13 @@ uint8_t CryptoSession::GetSecurityPatchLevel() { } CdmResponseType CryptoSession::Open(SecurityLevel requested_security_level) { - LOGD("CryptoSession::Open: requested_security_level: %s", - requested_security_level == kLevel3 - ? QUERY_VALUE_SECURITY_LEVEL_L3.c_str() - : QUERY_VALUE_SECURITY_LEVEL_DEFAULT.c_str()); - if (!IsInitialized()) return UNKNOWN_ERROR; + LOGD( + "Opening crypto session: requested_security_level: " + "requested_security_level = %s", + requested_security_level == kLevel3 + ? QUERY_VALUE_SECURITY_LEVEL_L3.c_str() + : QUERY_VALUE_SECURITY_LEVEL_DEFAULT.c_str()); + RETURN_IF_UNINITIALIZED(UNKNOWN_ERROR); if (open_) return NO_ERROR; CdmResponseType result = GetProvisioningMethod(requested_security_level, @@ -659,21 +652,24 @@ CdmResponseType CryptoSession::Open(SecurityLevel requested_security_level) { if (sts != OEMCrypto_SUCCESS) { WithStaticFieldReadLock( "Open() reporting OEMCrypto_OpenSession Failure", [&] { - LOGE("OEMCrypto_Open failed: %d, open sessions: %ld, initialized: %d", - sts, session_count_, (int)initialized_); + LOGE( + "OEMCrypto_Open failed: status = %d, session_count_ = %d," + " initialized_ = %s", + static_cast(sts), session_count_, + initialized_ ? "true" : "false"); }); return MapOEMCryptoResult(sts, OPEN_CRYPTO_SESSION_ERROR, "Open"); } oec_session_id_ = static_cast(sid); - LOGV("OpenSession: id= %lu", oec_session_id_); + LOGV("Opened session: id = %u", oec_session_id_); open_ = true; // Get System ID and save it. if (GetSystemIdInternal(&system_id_) == NO_ERROR) { metrics_->crypto_session_system_id_.Record(system_id_); } else { - LOGE("CryptoSession::Open: Failed to fetch system id."); + LOGE("Failed to fetch system ID"); metrics_->crypto_session_system_id_.SetError(LOAD_SYSTEM_ID_ERROR); return LOAD_SYSTEM_ID_ERROR; } @@ -693,7 +689,7 @@ CdmResponseType CryptoSession::Open(SecurityLevel requested_security_level) { sizeof(request_id_index)); if (!GetApiVersion(&api_version_)) { - LOGE("CryptoSession::Open: GetApiVersion failed"); + LOGE("Failed to get API version"); return USAGE_SUPPORT_GET_API_FAILED; } @@ -708,7 +704,7 @@ CdmResponseType CryptoSession::Open(SecurityLevel requested_security_level) { { // This block cannot use |WithStaticFieldWriteLock| because it needs // to unlock the lock partway through. - LOGV("Static Field Write Lock - Open() Initializing Usage Table"); + LOGV("Static field write lock: Open() initializing usage table"); std::unique_lock auto_lock(static_field_mutex_); UsageTableHeader** header = security_level == kSecurityLevelL1 @@ -747,7 +743,7 @@ CdmResponseType CryptoSession::Open(SecurityLevel requested_security_level) { } void CryptoSession::Close() { - LOGV("CloseSession: id=%lu open=%s", oec_session_id_, + LOGV("Closing crypto session: id = %u, open = %s", oec_session_id_, open_ ? "true" : "false"); if (!open_) return; @@ -768,7 +764,7 @@ CdmResponseType CryptoSession::PrepareRequest(const std::string& message, bool is_provisioning, std::string* signature) { if (signature == nullptr) { - LOGE("CryptoSession::PrepareRequest : No output destination provided."); + LOGE("Output parameter |signature| not provided"); return PARAMETER_NULL; } @@ -786,9 +782,7 @@ CdmResponseType CryptoSession::PrepareRequest(const std::string& message, CdmResponseType CryptoSession::PrepareRenewalRequest(const std::string& message, std::string* signature) { if (signature == nullptr) { - LOGE( - "CryptoSession::PrepareRenewalRequest : No output destination " - "provided."); + LOGE("Output parameter |signature| not provided"); return PARAMETER_NULL; } @@ -810,14 +804,14 @@ CdmResponseType CryptoSession::LoadKeys( key_session_.reset(new EntitlementKeySession(oec_session_id_, metrics_)); } - LOGV("LoadKeys: id=%lu", oec_session_id_); + LOGV("Loading key: id = %u", oec_session_id_); sts = key_session_->LoadKeys(message, signature, mac_key_iv, mac_key, keys, provider_session_token, &cipher_mode_, srm_requirement); }); if (sts != OEMCrypto_SUCCESS) { - LOGE("CryptoSession::LoadKeys: OEMCrypto_LoadKeys error=%d", sts); + LOGE("OEMCrypto_LoadKeys failed: status = %d", static_cast(sts)); } switch (sts) { @@ -889,7 +883,7 @@ CdmResponseType CryptoSession::LoadCertificatePrivateKey( }); metrics_->oemcrypto_get_oem_public_certificate_.Increment(sts); - LOGV("LoadDeviceRSAKey: id=%lu", oec_session_id_); + LOGV("Loading device RSA key: id = %u", oec_session_id_); WithOecSessionLock( "LoadCertificatePrivateKey() calling OEMCrypto_LoadDeviceRSAKey()", [&] { M_TIME(sts = OEMCrypto_LoadDeviceRSAKey( @@ -919,7 +913,7 @@ CdmResponseType CryptoSession::RefreshKeys(const std::string& message, ko->key_control = GetSubstring(message, ki->key_control(), !has_key_control); } - LOGV("RefreshKeys: id=%lu", oec_session_id_); + LOGV("Refreshing keys: id = %u", oec_session_id_); OEMCryptoResult refresh_sts; WithOecSessionLock("RefreshKeys", [&] { M_TIME(refresh_sts = OEMCrypto_RefreshKeys( @@ -994,9 +988,9 @@ CdmResponseType CryptoSession::GenerateDerivedKeys( CdmResponseType CryptoSession::GenerateSignature(const std::string& message, std::string* signature) { - LOGV("GenerateSignature: id=%lu", oec_session_id_); + LOGV("Generating signature: id = %u", oec_session_id_); if (signature == nullptr) { - LOGE("GenerateSignature: null signature string"); + LOGE("Output parameter |signature| not provided"); return PARAMETER_NULL; } @@ -1034,9 +1028,9 @@ CdmResponseType CryptoSession::GenerateSignature(const std::string& message, CdmResponseType CryptoSession::GenerateRsaSignature(const std::string& message, std::string* signature) { - LOGV("GenerateRsaSignature: id=%lu", oec_session_id_); + LOGV("Generating RSA signature: id = %u", oec_session_id_); if (signature == nullptr) { - LOGE("GenerateRsaSignature: null signature string"); + LOGE("Output parameter |signature| not provided"); return PARAMETER_NULL; } @@ -1196,22 +1190,16 @@ CdmResponseType CryptoSession::Decrypt(const CdmDecryptionParameters& params) { } bool CryptoSession::UsageInformationSupport(bool* has_support) { - LOGV("CryptoSession::UsageInformationSupport"); - if (!open_) { - LOGW("CryptoSession::UsageInformationSupport: session not open"); - return false; - } + LOGV("Checking if usage information is supported"); + RETURN_IF_NOT_OPEN(false); return UsageInformationSupport(requested_security_level_, has_support); } bool CryptoSession::UsageInformationSupport(SecurityLevel security_level, bool* has_support) { - LOGV("CryptoSession::UsageInformationSupport"); - if (!IsInitialized()) { - LOGW("CryptoSession::UsageInformationSupport: not initialized"); - return false; - } - + LOGV("Checking if usage information is supported: security_level = %d", + static_cast(security_level)); + RETURN_IF_UNINITIALIZED(false); WithOecReadLock("UsageInformationSupport", [&] { *has_support = OEMCrypto_SupportsUsageTable(security_level); }); @@ -1219,11 +1207,11 @@ bool CryptoSession::UsageInformationSupport(SecurityLevel security_level, } CdmResponseType CryptoSession::UpdateUsageInformation() { - LOGV("CryptoSession::UpdateUsageInformation: id=%lu", oec_session_id_); - if (!IsInitialized()) return UNKNOWN_ERROR; + LOGV("Updating usage information: id = %u", oec_session_id_); + RETURN_IF_UNINITIALIZED(UNKNOWN_ERROR); - if (usage_table_header_ != NULL) { - LOGV("UpdateUsageInformation: deprecated for OEMCrypto v13+"); + if (usage_table_header_ != nullptr) { + LOGV("Deprecated for OEMCrypto v13+"); return NO_ERROR; } @@ -1232,7 +1220,8 @@ CdmResponseType CryptoSession::UpdateUsageInformation() { [&] { status = OEMCrypto_UpdateUsageTable(); }); metrics_->oemcrypto_update_usage_table_.Increment(status); if (status != OEMCrypto_SUCCESS) { - LOGE("CryptoSession::UpdateUsageInformation: error=%ld", status); + LOGE("OEMCrypto_UpdateUsageTable failed: status = %d", + static_cast(status)); return UNKNOWN_ERROR; } return NO_ERROR; @@ -1240,7 +1229,7 @@ CdmResponseType CryptoSession::UpdateUsageInformation() { CdmResponseType CryptoSession::DeactivateUsageInformation( const std::string& provider_session_token) { - LOGV("DeactivateUsageInformation: id=%lu", oec_session_id_); + LOGV("Deactivating usage information: id = %u", oec_session_id_); uint8_t* pst = reinterpret_cast( const_cast(provider_session_token.data())); @@ -1254,7 +1243,8 @@ CdmResponseType CryptoSession::DeactivateUsageInformation( metrics_->oemcrypto_deactivate_usage_entry_.Increment(status); if (status != OEMCrypto_SUCCESS) { - LOGE("CryptoSession::DeactivateUsageInformation: error=%ld", status); + LOGE("OEMCrypto_DeactivateUsageEntry failed: status = %d", + static_cast(status)); } switch (status) { @@ -1275,10 +1265,10 @@ CdmResponseType CryptoSession::GenerateUsageReport( const std::string& provider_session_token, std::string* usage_report, UsageDurationStatus* usage_duration_status, int64_t* seconds_since_started, int64_t* seconds_since_last_played) { - LOGV("GenerateUsageReport: id=%lu", oec_session_id_); + LOGV("Generating usage report: id = %u", oec_session_id_); - if (nullptr == usage_report) { - LOGE("CryptoSession::GenerateUsageReport: usage_report parameter is null"); + if (usage_report == nullptr) { + LOGE("Output parameter |usage_report| not provided"); return PARAMETER_NULL; } @@ -1322,8 +1312,10 @@ CdmResponseType CryptoSession::GenerateUsageReport( Unpacked_PST_Report pst_report(&buffer[0]); *usage_duration_status = kUsageDurationsInvalid; if (usage_length < pst_report.report_size()) { - LOGE("CryptoSession::GenerateUsageReport: usage report too small=%ld", - usage_length); + LOGE( + "Parsed usage report smaller than expected: " + "usage_length = %zu, report_size = %zu", + usage_length, pst_report.report_size()); return NO_ERROR; // usage report available but no duration information } @@ -1331,16 +1323,19 @@ CdmResponseType CryptoSession::GenerateUsageReport( *usage_duration_status = kUsageDurationPlaybackNotBegun; return NO_ERROR; } - LOGV("OEMCrypto_PST_Report.status: %d\n", pst_report.status()); + LOGV("OEMCrypto_PST_Report.status: %d\n", + static_cast(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", + static_cast(pst_report.clock_security_level())); + LOGV("OEMCrypto_PST_Report.pst_length: %d\n", + static_cast(pst_report.pst_length())); + LOGV("OEMCrypto_PST_Report.padding: %d\n", + static_cast(pst_report.padding())); + LOGV("OEMCrypto_PST_Report.seconds_since_license_received: %ld\n", pst_report.seconds_since_license_received()); - LOGV("OEMCrypto_PST_Report.seconds_since_first_decrypt: %lld\n", + LOGV("OEMCrypto_PST_Report.seconds_since_first_decrypt: %ld\n", pst_report.seconds_since_first_decrypt()); - LOGV("OEMCrypto_PST_Report.seconds_since_last_decrypt: %lld\n", + LOGV("OEMCrypto_PST_Report.seconds_since_last_decrypt: %ld\n", pst_report.seconds_since_last_decrypt()); LOGV("OEMCrypto_PST_Report: %s\n", b2a_hex(*usage_report).c_str()); @@ -1367,9 +1362,9 @@ CdmResponseType CryptoSession::GenerateUsageReport( CdmResponseType CryptoSession::ReleaseUsageInformation( const std::string& message, const std::string& signature, const std::string& provider_session_token) { - LOGV("ReleaseUsageInformation: id=%lu", oec_session_id_); - if (usage_table_header_ != NULL) { - LOGW("ReleaseUsageInformation: deprecated for OEMCrypto v13+"); + LOGV("Releasing usage information: id = %u", oec_session_id_); + if (usage_table_header_ != nullptr) { + LOGW("Releasing usage information is deprecated for OEMCrypto v13+"); return NO_ERROR; } @@ -1386,8 +1381,8 @@ CdmResponseType CryptoSession::ReleaseUsageInformation( metrics_->oemcrypto_delete_usage_entry_.Increment(status); if (OEMCrypto_SUCCESS != status) { - LOGE("CryptoSession::ReleaseUsageInformation: Report Usage error=%ld", - status); + LOGE("OEMCrypto_DeleteUsageEntry failed: status = %d", + static_cast(status)); return UNKNOWN_ERROR; } @@ -1398,7 +1393,7 @@ CdmResponseType CryptoSession::ReleaseUsageInformation( CdmResponseType CryptoSession::DeleteUsageInformation( const std::string& provider_session_token) { CdmResponseType response = NO_ERROR; - LOGV("CryptoSession::DeleteUsageInformation"); + LOGV("Deleting usage information: id = %u", oec_session_id_); OEMCryptoResult status; WithOecWriteLock("DeleteUsageInformation", [&] { status = OEMCrypto_ForceDeleteUsageEntry( @@ -1407,10 +1402,8 @@ CdmResponseType CryptoSession::DeleteUsageInformation( }); metrics_->oemcrypto_force_delete_usage_entry_.Increment(status); if (OEMCrypto_SUCCESS != status) { - LOGE( - "CryptoSession::DeleteUsageInformation: Delete Usage Table error " - "= %ld", - status); + LOGE("OEMCrypto_ForceDeleteUsageEntry failed: status = %d", + static_cast(status)); response = UNKNOWN_ERROR; } if (usage_support_type_ == kUsageTableSupport) UpdateUsageInformation(); @@ -1419,7 +1412,7 @@ CdmResponseType CryptoSession::DeleteUsageInformation( CdmResponseType CryptoSession::DeleteMultipleUsageInformation( const std::vector& provider_session_tokens) { - LOGV("CryptoSession::DeleteMultipleUsageInformation"); + LOGV("Deleting multiple usage information: id = %u", oec_session_id_); CdmResponseType response = NO_ERROR; WithOecWriteLock("DeleteMultipleUsageInformation", [&] { for (size_t i = 0; i < provider_session_tokens.size(); ++i) { @@ -1428,10 +1421,8 @@ CdmResponseType CryptoSession::DeleteMultipleUsageInformation( provider_session_tokens[i].length()); metrics_->oemcrypto_force_delete_usage_entry_.Increment(status); if (OEMCrypto_SUCCESS != status) { - LOGW( - "CryptoSession::DeleteMultipleUsageInformation: " - "Delete Usage Table error =%ld", - status); + LOGW("OEMCrypto_ForceDeleteUsageEntry failed: index = %zu, status = %d", + i, static_cast(status)); response = UNKNOWN_ERROR; } } @@ -1441,16 +1432,14 @@ CdmResponseType CryptoSession::DeleteMultipleUsageInformation( } CdmResponseType CryptoSession::DeleteAllUsageReports() { - LOGV("DeleteAllUsageReports"); + LOGV("Deleting all usage reports"); OEMCryptoResult status; WithOecWriteLock("DeleteAllUsageReports", [&] { status = OEMCrypto_DeleteOldUsageTable(); }); metrics_->oemcrypto_delete_usage_table_.Increment(status); if (OEMCrypto_SUCCESS != status) { - LOGE( - "CryptoSession::DeleteAllUsageReports: Delete Usage Table error " - "=%ld", - status); + LOGE("OEMCrypto_DeleteOldUsageTable failed: status = %d", + static_cast(status)); } if (usage_support_type_ == kUsageTableSupport) UpdateUsageInformation(); @@ -1468,7 +1457,7 @@ bool CryptoSession::IsAntiRollbackHwPresent() { CdmResponseType CryptoSession::GenerateNonce(uint32_t* nonce) { if (nonce == nullptr) { - LOGE("input parameter is null"); + LOGE("Output parameter |nonce| not provided"); return PARAMETER_NULL; } @@ -1501,7 +1490,7 @@ CdmResponseType CryptoSession::RewrapCertificate( const std::string& nonce, const std::string& private_key, const std::string& iv, const std::string& wrapping_key, std::string* wrapped_private_key) { - LOGV("CryptoSession::RewrapCertificate, session id=%lu", oec_session_id_); + LOGV("Rewrapping certificate: id = %u", oec_session_id_); if (pre_provision_token_type_ == kClientTokenKeybox) { return RewrapDeviceRSAKey(signed_message, signature, nonce, private_key, iv, @@ -1512,10 +1501,8 @@ CdmResponseType CryptoSession::RewrapCertificate( wrapping_key, wrapped_private_key); } else { - LOGE( - "CryptoSession::RewrapCertificate, Bad pre-provision type=%d: " - "session id=%lu", - pre_provision_token_type_, oec_session_id_); + LOGE("Bad pre-provision type: %d, id = %u", + static_cast(pre_provision_token_type_), oec_session_id_); return UNKNOWN_CLIENT_TOKEN_TYPE; } } @@ -1524,7 +1511,7 @@ CdmResponseType CryptoSession::RewrapDeviceRSAKey( const std::string& message, const std::string& signature, const std::string& nonce, const std::string& enc_rsa_key, const std::string& rsa_key_iv, std::string* wrapped_rsa_key) { - LOGV("CryptoSession::RewrapDeviceRSAKey, session id=%lu", oec_session_id_); + LOGV("Rewrapping device RSA key: id = %u", oec_session_id_); const uint8_t* signed_msg = reinterpret_cast(message.data()); const uint8_t* msg_rsa_key = NULL; @@ -1577,7 +1564,7 @@ CdmResponseType CryptoSession::RewrapDeviceRSAKey30( const std::string& message, const std::string& nonce, const std::string& private_key, const std::string& iv, const std::string& wrapping_key, std::string* wrapped_private_key) { - LOGV("CryptoSession::RewrapDeviceRSAKey30, session id=%lu", oec_session_id_); + LOGV("Rewrapping Device RSA key 30: id = %u", oec_session_id_); const uint8_t* signed_msg = reinterpret_cast(message.data()); const uint8_t* msg_private_key = NULL; @@ -1627,26 +1614,23 @@ CdmResponseType CryptoSession::RewrapDeviceRSAKey30( CdmResponseType CryptoSession::GetHdcpCapabilities(HdcpCapability* current, HdcpCapability* max) { - LOGV("CryptoSession::GetHdcpCapabilities: id=%lu", oec_session_id_); - if (!open_) { - LOGW("CryptoSession::GetHdcpCapabilities: session not open"); - return CRYPTO_SESSION_NOT_OPEN; - } + LOGV("Getting HDCP capabilities: id = %u", oec_session_id_); + RETURN_IF_NOT_OPEN(CRYPTO_SESSION_NOT_OPEN); return GetHdcpCapabilities(requested_security_level_, current, max); } CdmResponseType CryptoSession::GetHdcpCapabilities(SecurityLevel security_level, HdcpCapability* current, HdcpCapability* max) { - LOGV("CryptoSession::GetHdcpCapabilities"); - if (!IsInitialized()) { - LOGW("CryptoSession::GetHdcpCapabilities: not initialized"); - return CRYPTO_SESSION_NOT_INITIALIZED; + LOGV("Getting HDCP capabilities: id = %u, security_level = %d", + oec_session_id_, static_cast(security_level)); + RETURN_IF_UNINITIALIZED(CRYPTO_SESSION_NOT_INITIALIZED); + if (current == nullptr) { + LOGE("Output parameter |current| not provided"); + return PARAMETER_NULL; } - if (current == nullptr || max == nullptr) { - LOGE( - "CryptoSession::GetHdcpCapabilities: |current|, |max| cannot be " - "NULL"); + if (max == nullptr) { + LOGE("Output parameter |max| not provided"); return PARAMETER_NULL; } OEMCryptoResult status; @@ -1668,12 +1652,10 @@ CdmResponseType CryptoSession::GetHdcpCapabilities(SecurityLevel security_level, bool CryptoSession::GetSupportedCertificateTypes( SupportedCertificateTypes* support) { - LOGV("GetSupportedCertificateTypes: id=%lu", oec_session_id_); - if (!IsInitialized()) return false; - if (support == NULL) { - LOGE( - "CryptoSession::GetSupportedCertificateTypes: |support| cannot be " - "NULL"); + LOGV("Getting supported certificate types: id = %u", oec_session_id_); + RETURN_IF_UNINITIALIZED(false); + if (support == nullptr) { + LOGE("Output parameter |support| not provided"); return false; } @@ -1690,7 +1672,7 @@ bool CryptoSession::GetSupportedCertificateTypes( CdmResponseType CryptoSession::GetRandom(size_t data_length, uint8_t* random_data) { if (random_data == nullptr) { - LOGE("CryptoSession::GetRandom: random data destination not provided"); + LOGE("Output parameter |random_data| not provided"); return PARAMETER_NULL; } OEMCryptoResult sts; @@ -1703,13 +1685,11 @@ CdmResponseType CryptoSession::GetRandom(size_t data_length, CdmResponseType CryptoSession::GetNumberOfOpenSessions( SecurityLevel security_level, size_t* count) { - LOGV("GetNumberOfOpenSessions"); - if (!IsInitialized()) { - LOGW("CryptoSession::GetNumberOfOpenSessions: not initialized"); - return CRYPTO_SESSION_NOT_INITIALIZED; - } + LOGV("Getting number of open sessions: id = %u, security_level = %d", + oec_session_id_, static_cast(security_level)); + RETURN_IF_UNINITIALIZED(CRYPTO_SESSION_NOT_INITIALIZED); if (count == nullptr) { - LOGE("CryptoSession::GetNumberOfOpenSessions: |count| cannot be NULL"); + LOGE("Output parameter |count| not provided"); return PARAMETER_NULL; } @@ -1732,14 +1712,12 @@ CdmResponseType CryptoSession::GetNumberOfOpenSessions( CdmResponseType CryptoSession::GetMaxNumberOfSessions( SecurityLevel security_level, size_t* max) { - LOGV("GetMaxNumberOfSessions"); - if (!IsInitialized()) { - LOGW("CryptoSession::GetMaxNumberOfSessions: not initialized"); - return CRYPTO_SESSION_NOT_INITIALIZED; - } + LOGV("Getting max number of sessions: id = %u, security_level = %d", + oec_session_id_, static_cast(security_level)); + RETURN_IF_UNINITIALIZED(CRYPTO_SESSION_NOT_INITIALIZED); if (max == nullptr) { - LOGE("CryptoSession::GetMaxNumberOfSessions: |max| cannot be NULL"); + LOGE("Output parameter |max| not provided"); return PARAMETER_NULL; } @@ -1761,10 +1739,10 @@ CdmResponseType CryptoSession::GetMaxNumberOfSessions( } CdmResponseType CryptoSession::GetSrmVersion(uint16_t* srm_version) { - LOGV("GetSrmVersion"); - if (!IsInitialized()) return CRYPTO_SESSION_NOT_INITIALIZED; + LOGV("Getting SRM version"); + RETURN_IF_UNINITIALIZED(CRYPTO_SESSION_NOT_INITIALIZED); if (srm_version == nullptr) { - LOGE("CryptoSession::GetSrmVersion: |srm_version| cannot be NULL"); + LOGE("Output parameter |srm_version| not provided"); return PARAMETER_NULL; } @@ -1776,9 +1754,7 @@ CdmResponseType CryptoSession::GetSrmVersion(uint16_t* srm_version) { // SRM is an optional feature. Whether it is implemented is up to the // discretion of OEMs if (status == OEMCrypto_ERROR_NOT_IMPLEMENTED) { - LOGV( - "CryptoSession::GetSrmVersion: OEMCrypto_GetCurrentSRMVersion not " - "implemented"); + LOGV("OEMCrypto_GetCurrentSRMVersion not implemented"); return NOT_IMPLEMENTED_ERROR; } @@ -1787,17 +1763,17 @@ CdmResponseType CryptoSession::GetSrmVersion(uint16_t* srm_version) { } bool CryptoSession::IsSrmUpdateSupported() { - LOGV("IsSrmUpdateSupported"); + LOGV("Checking if SRM update is supported"); if (!IsInitialized()) return false; return WithOecReadLock("IsSrmUpdateSupported", [&] { return OEMCrypto_IsSRMUpdateSupported(); }); } CdmResponseType CryptoSession::LoadSrm(const std::string& srm) { - LOGV("LoadSrm"); - if (!IsInitialized()) return CRYPTO_SESSION_NOT_INITIALIZED; + LOGV("Loading SRM"); + RETURN_IF_UNINITIALIZED(CRYPTO_SESSION_NOT_INITIALIZED); if (srm.empty()) { - LOGE("CryptoSession::LoadSrm: |srm| cannot be empty"); + LOGE("SRM is empty"); return INVALID_SRM_LIST; } @@ -1811,23 +1787,18 @@ CdmResponseType CryptoSession::LoadSrm(const std::string& srm) { } bool CryptoSession::GetResourceRatingTier(uint32_t* tier) { - LOGV("CryptoSession::GetResourceRatingTier"); - if (!open_) { - LOGW("CryptoSession::GetResourceRatingTier: session not open"); - return false; - } + LOGV("Getting resource rating tier"); + RETURN_IF_NOT_OPEN(false); return GetResourceRatingTier(requested_security_level_, tier); } bool CryptoSession::GetResourceRatingTier(SecurityLevel security_level, uint32_t* tier) { - LOGV("GetResourceRatingTier"); - if (!IsInitialized()) { - LOGW("CryptoSession::GetResourceRatingTier: not initialized"); - return false; - } + LOGV("Getting resource rating tier: security_level = %d", + static_cast(security_level)); + RETURN_IF_UNINITIALIZED(false); if (tier == nullptr) { - LOGE("tier destination not provided"); + LOGE("Output parameter |tier| not provided"); return false; } WithOecReadLock("GetResourceRatingTier", [&] { @@ -1838,7 +1809,7 @@ bool CryptoSession::GetResourceRatingTier(SecurityLevel security_level, uint32_t api_version; if (GetApiVersion(security_level, &api_version)) { if (api_version >= OEM_CRYPTO_API_VERSION_SUPPORTS_RESOURCE_RATING_TIER) { - LOGW("GetResourceRatingTier: invalid resource rating tier: %d", *tier); + LOGW("Invalid resource rating tier: %u", *tier); } } } @@ -1846,23 +1817,18 @@ bool CryptoSession::GetResourceRatingTier(SecurityLevel security_level, } bool CryptoSession::GetBuildInformation(std::string* info) { - LOGV("CryptoSession::GetBuildInformation"); - if (!open_) { - LOGW("CryptoSession::GetBuildInformation: session not open"); - return false; - } + LOGV("Getting build information"); + RETURN_IF_NOT_OPEN(false); return GetBuildInformation(requested_security_level_, info); } bool CryptoSession::GetBuildInformation(SecurityLevel security_level, std::string* info) { - LOGV("GetBuildInformation"); - if (!IsInitialized()) { - LOGW("CryptoSession::GetBuildInformation: not initialized"); - return false; - } + LOGV("Getting build information: security_level = %d", + static_cast(security_level)); + RETURN_IF_UNINITIALIZED(false); if (info == nullptr) { - LOGE("CryptoSession::GetBuildInformation: |info| cannot be empty"); + LOGE("Output parameter |info| not provided"); return false; } const char* build_information; @@ -1870,7 +1836,7 @@ bool CryptoSession::GetBuildInformation(SecurityLevel security_level, build_information = OEMCrypto_BuildInformation(security_level); }); if (build_information == nullptr) { - LOGE("CryptoSession::GetBuildInformation: returned null"); + LOGE("OEMCrypto_BuildInformation failed: Returned null"); return false; } @@ -1879,11 +1845,8 @@ bool CryptoSession::GetBuildInformation(SecurityLevel security_level, } uint32_t CryptoSession::IsDecryptHashSupported(SecurityLevel security_level) { - LOGV("IsDecryptHashSupported"); - if (!IsInitialized()) { - LOGW("CryptoSession::IsDecryptHashSupported: not initialized"); - return false; - } + LOGV("Checking if decrypt hash is supported"); + RETURN_IF_UNINITIALIZED(false); uint32_t secure_decrypt_support; WithOecReadLock("IsDecryptHashSupported", [&] { @@ -1895,8 +1858,8 @@ uint32_t CryptoSession::IsDecryptHashSupported(SecurityLevel security_level) { case OEMCrypto_Partner_Defined_Hash: break; default: - LOGW("OEMCrypto_SupportsDecryptHash returned unexpected result: %d", - secure_decrypt_support); + LOGE("OEMCrypto_SupportsDecryptHash failed: result = %d", + static_cast(secure_decrypt_support)); secure_decrypt_support = OEMCrypto_Hash_Not_Supported; break; } @@ -1905,7 +1868,7 @@ uint32_t CryptoSession::IsDecryptHashSupported(SecurityLevel security_level) { CdmResponseType CryptoSession::SetDecryptHash(uint32_t frame_number, const std::string& hash) { - LOGV("SetDecryptHash"); + LOGV("Setting decrypt hash"); OEMCryptoResult sts; WithOecSessionLock("SetDecryptHash", [&] { sts = OEMCrypto_SetDecryptHash( @@ -1918,9 +1881,9 @@ CdmResponseType CryptoSession::SetDecryptHash(uint32_t frame_number, } CdmResponseType CryptoSession::GetDecryptHashError(std::string* error_string) { - LOGV("GetDecryptHashError"); + LOGV("Getting decrypt hash error"); if (error_string == nullptr) { - LOGE("CryptoSession::GetDecryptHashError: |error_string| not provided"); + LOGE("Output parameter |error_string| not provided"); return PARAMETER_NULL; } error_string->clear(); @@ -1933,7 +1896,8 @@ CdmResponseType CryptoSession::GetDecryptHashError(std::string* error_string) { error_string->assign(std::to_string(sts)); if (sts != OEMCrypto_SUCCESS) { - LOGE("GetDecryptHashError: failed with error %d", sts); + LOGE("OEMCrypto_GetHashErrorCode failed: status = %d", + static_cast(sts)); } switch (sts) { @@ -1959,9 +1923,9 @@ CdmResponseType CryptoSession::GenericEncrypt(const std::string& in_buffer, const std::string& iv, CdmEncryptionAlgorithm algorithm, std::string* out_buffer) { - LOGV("GenericEncrypt: id=%lu", oec_session_id_); + LOGV("Generic encrypt: id = %u", oec_session_id_); if (out_buffer == nullptr) { - LOGE("CryptoSession::GenericEncrypt: out_buffer not provided"); + LOGE("Output parameter |out_buffer| not provided"); return PARAMETER_NULL; } @@ -1995,7 +1959,8 @@ CdmResponseType CryptoSession::GenericEncrypt(const std::string& in_buffer, }); if (OEMCrypto_SUCCESS != sts) { - LOGE("GenericEncrypt: OEMCrypto_Generic_Encrypt err=%d", sts); + LOGE("OEMCrypto_Generic_Encrypt failed: status = %d", + static_cast(sts)); } switch (sts) { @@ -2022,9 +1987,9 @@ CdmResponseType CryptoSession::GenericDecrypt(const std::string& in_buffer, const std::string& iv, CdmEncryptionAlgorithm algorithm, std::string* out_buffer) { - LOGV("GenericDecrypt: id=%lu", oec_session_id_); + LOGV("Generic decrypt: id = %u", oec_session_id_); if (out_buffer == nullptr) { - LOGE("CryptoSession::GenericDecrypt: out_buffer not provided"); + LOGE("Output parameter |out_buffer| not provided"); return PARAMETER_NULL; } @@ -2058,7 +2023,8 @@ CdmResponseType CryptoSession::GenericDecrypt(const std::string& in_buffer, }); if (OEMCrypto_SUCCESS != sts) { - LOGE("GenericDecrypt: OEMCrypto_Generic_Decrypt err=%d", sts); + LOGE("OEMCrypto_Generic_Decrypt failed: status = %d", + static_cast(sts)); } switch (sts) { @@ -2084,9 +2050,9 @@ CdmResponseType CryptoSession::GenericSign(const std::string& message, const std::string& key_id, CdmSigningAlgorithm algorithm, std::string* signature) { - LOGV("GenericSign: id=%lu", oec_session_id_); + LOGV("Generic sign: id = %u", oec_session_id_); if (signature == nullptr) { - LOGE("CryptoSession::GenericSign: signature not provided"); + LOGE("Output parameter |signature| not provided"); return PARAMETER_NULL; } @@ -2131,7 +2097,7 @@ CdmResponseType CryptoSession::GenericSign(const std::string& message, signature->resize(length); } - LOGE("GenericSign: OEMCrypto_Generic_Sign err=%d", sts); + LOGE("OEMCrypto_Generic_Sign failed: status = %d", static_cast(sts)); switch (sts) { case OEMCrypto_ERROR_KEY_EXPIRED: @@ -2154,7 +2120,7 @@ CdmResponseType CryptoSession::GenericVerify(const std::string& message, const std::string& key_id, CdmSigningAlgorithm algorithm, const std::string& signature) { - LOGV("GenericVerify: id=%lu", oec_session_id_); + LOGV("Generic verify: id = %u", oec_session_id_); OEMCrypto_Algorithm oec_algorithm = GenericSigningAlgorithm(algorithm); if (oec_algorithm == kInvalidAlgorithm) { @@ -2180,7 +2146,7 @@ CdmResponseType CryptoSession::GenericVerify(const std::string& message, }); if (OEMCrypto_SUCCESS != sts) { - LOGE("GenericVerify: OEMCrypto_Generic_Verify err=%d", sts); + LOGE("OEMCrypto_Generic_Verify failed: status = %d", static_cast(sts)); } switch (sts) { @@ -2204,10 +2170,10 @@ CdmResponseType CryptoSession::GenericVerify(const std::string& message, CdmResponseType CryptoSession::GetUsageSupportType( CdmUsageSupportType* usage_support_type) { - LOGV("GetUsageSupportType: id=%lu", oec_session_id_); + LOGV("Getting usage support type: id = %u", oec_session_id_); - if (usage_support_type == NULL) { - LOGE("GetUsageSupportType: usage_support_type param not provided"); + if (usage_support_type == nullptr) { + LOGE("Output parameter |usage_support_type| not provided"); return INVALID_PARAMETERS_ENG_23; } @@ -2218,7 +2184,7 @@ CdmResponseType CryptoSession::GetUsageSupportType( bool has_support = false; if (!UsageInformationSupport(&has_support)) { - LOGE("GetUsageSupportType: UsageInformationSupport failed"); + LOGE("UsageInformationSupport failed"); return USAGE_INFORMATION_SUPPORT_FAILED; } @@ -2236,10 +2202,10 @@ CdmResponseType CryptoSession::GetUsageSupportType( CdmResponseType CryptoSession::CreateUsageTableHeader( CdmUsageTableHeader* usage_table_header) { - LOGV("CreateUsageTableHeader: id=%lu", oec_session_id_); + LOGV("Creating usage table header: id = %u", oec_session_id_); - if (usage_table_header == NULL) { - LOGE("CreateUsageTableHeader: usage_table_header param not provided"); + if (usage_table_header == nullptr) { + LOGE("Output parameter |usage_table_header| not provided"); return INVALID_PARAMETERS_ENG_17; } @@ -2278,7 +2244,7 @@ CdmResponseType CryptoSession::CreateUsageTableHeader( CdmResponseType CryptoSession::LoadUsageTableHeader( const CdmUsageTableHeader& usage_table_header) { - LOGV("LoadUsageTableHeader: id=%lu", oec_session_id_); + LOGV("Loading usage table header: id = %u", oec_session_id_); OEMCryptoResult result; WithOecWriteLock("LoadUsageTableHeader", [&] { @@ -2291,12 +2257,10 @@ CdmResponseType CryptoSession::LoadUsageTableHeader( if (result != OEMCrypto_SUCCESS) { if (result == OEMCrypto_WARNING_GENERATION_SKEW) { - LOGW( - "LoadUsageTableHeader: OEMCrypto_LoadUsageTableHeader warning: " - "generation skew"); + LOGW("OEMCrypto_LoadUsageTableHeader warning: generation skew"); } else { - LOGE("LoadUsageTableHeader: OEMCrypto_LoadUsageTableHeader error: %d", - result); + LOGE("OEMCrypto_LoadUsageTableHeader failed: status = %d", + static_cast(result)); } } @@ -2319,10 +2283,10 @@ CdmResponseType CryptoSession::LoadUsageTableHeader( } CdmResponseType CryptoSession::CreateUsageEntry(uint32_t* entry_number) { - LOGV("CreateUsageEntry: id=%lu", oec_session_id_); + LOGV("Creating usage entry: id = %u", oec_session_id_); - if (entry_number == NULL) { - LOGE("CreateUsageEntry: entry_number param not provided"); + if (entry_number == nullptr) { + LOGE("Output parameter |entry_number| not provided"); return INVALID_PARAMETERS_ENG_18; } @@ -2333,7 +2297,8 @@ CdmResponseType CryptoSession::CreateUsageEntry(uint32_t* entry_number) { }); if (result != OEMCrypto_SUCCESS) { - LOGE("CreateUsageEntry: OEMCrypto_CreateNewUsageEntry error: %d", result); + LOGE("OEMCrypto_CreateNewUsageEntry failed: status = %d", + static_cast(result)); } switch (result) { @@ -2352,7 +2317,7 @@ CdmResponseType CryptoSession::CreateUsageEntry(uint32_t* entry_number) { CdmResponseType CryptoSession::LoadUsageEntry( uint32_t entry_number, const CdmUsageEntry& usage_entry) { - LOGV("LoadUsageEntry: id=%lu", oec_session_id_); + LOGV("Loading usage entry: id = %u", oec_session_id_); OEMCryptoResult result; WithOecWriteLock("LoadUsageEntry", [&] { @@ -2365,9 +2330,10 @@ CdmResponseType CryptoSession::LoadUsageEntry( if (result != OEMCrypto_SUCCESS) { if (result == OEMCrypto_WARNING_GENERATION_SKEW) { - LOGW("LoadUsageEntry: OEMCrypto_LoadUsageEntry warning: generation skew"); + LOGW("OEMCrypto_LoadUsageEntry warning: generation skew"); } else { - LOGE("LoadUsageEntry: OEMCrypto_LoadUsageEntry error: %d", result); + LOGE("OEMCrypto_LoadUsageEntry failed: status = %d", + static_cast(result)); } } @@ -2392,15 +2358,15 @@ CdmResponseType CryptoSession::LoadUsageEntry( CdmResponseType CryptoSession::UpdateUsageEntry( CdmUsageTableHeader* usage_table_header, CdmUsageEntry* usage_entry) { - LOGV("UpdateUsageEntry: id=%lu", oec_session_id_); + LOGV("Updating usage entry: id = %u", oec_session_id_); - if (usage_table_header == NULL) { - LOGE("UpdateUsageEntry: usage_table_header param not provided"); + if (usage_table_header == nullptr) { + LOGE("Output parameter |usage_table_header| not provided"); return INVALID_PARAMETERS_ENG_19; } - if (usage_entry == NULL) { - LOGE("UpdateUsageEntry: usage_entry param not provided"); + if (usage_entry == nullptr) { + LOGE("Output parameter |usage_entry| not provided"); return INVALID_PARAMETERS_ENG_20; } @@ -2440,10 +2406,10 @@ CdmResponseType CryptoSession::UpdateUsageEntry( CdmResponseType CryptoSession::ShrinkUsageTableHeader( uint32_t new_entry_count, CdmUsageTableHeader* usage_table_header) { - LOGV("ShrinkUsageTableHeader: id=%lu", oec_session_id_); + LOGV("Shrinking usage table header: id = %u", oec_session_id_); - if (usage_table_header == NULL) { - LOGE("ShrinkUsageTableHeader: usage_table_header param not provided"); + if (usage_table_header == nullptr) { + LOGE("Output parameter |usage_table_header| not provided"); return INVALID_PARAMETERS_ENG_21; } @@ -2478,7 +2444,7 @@ CdmResponseType CryptoSession::ShrinkUsageTableHeader( } CdmResponseType CryptoSession::MoveUsageEntry(uint32_t new_entry_number) { - LOGV("MoveUsageEntry: id=%lu", oec_session_id_); + LOGV("Moving usage entry: id = %u", oec_session_id_); OEMCryptoResult result; WithOecWriteLock("MoveUsageEntry", [&] { @@ -2495,14 +2461,14 @@ bool CryptoSession::CreateOldUsageEntry( uint64_t time_since_last_decrypt, UsageDurationStatus usage_duration_status, const std::string& server_mac_key, const std::string& client_mac_key, const std::string& provider_session_token) { - LOGV("CreateOldUsageEntry"); + LOGV("Creating old usage entry"); - if (server_mac_key.size() < MAC_KEY_SIZE || - client_mac_key.size() < MAC_KEY_SIZE) { - LOGE( - "CreateOldUsageEntry: Invalid mac key size: server mac key size %d, " - "client mac key size: %d", - server_mac_key.size(), client_mac_key.size()); + if (server_mac_key.size() < MAC_KEY_SIZE) { + LOGE("Invalid server MAC key size: size = %zu", server_mac_key.size()); + return false; + } + if (client_mac_key.size() < MAC_KEY_SIZE) { + LOGE("Invalid client MAC key size: size = %zu", client_mac_key.size()); return false; } @@ -2518,8 +2484,8 @@ bool CryptoSession::CreateOldUsageEntry( status = kActive; break; default: - LOGE("CreateOldUsageEntry: Unrecognized usage duration status: %d", - usage_duration_status); + LOGE("Unrecognized usage duration status: %d", + static_cast(usage_duration_status)); return false; } @@ -2536,8 +2502,8 @@ bool CryptoSession::CreateOldUsageEntry( }); if (result != OEMCrypto_SUCCESS) { - LOGE("CreateOldUsageEntry: OEMCrypto_CreateOldUsageEntry error: %d", - result); + LOGE("OEMCrypto_CreateOldUsageEntry failed: status = %d", + static_cast(result)); return false; } return true; @@ -2545,7 +2511,7 @@ bool CryptoSession::CreateOldUsageEntry( CdmResponseType CryptoSession::CopyOldUsageEntry( const std::string& provider_session_token) { - LOGV("CopyOldUsageEntry: id=%lu", oec_session_id_); + LOGV("Copying old usage entry: id = %u", oec_session_id_); OEMCryptoResult result; WithOecWriteLock("CopyOldUsageEntry", [&] { @@ -2563,7 +2529,7 @@ CdmResponseType CryptoSession::CopyOldUsageEntry( bool CryptoSession::GetAnalogOutputCapabilities(bool* can_support_output, bool* can_disable_output, bool* can_support_cgms_a) { - LOGV("GetAnalogOutputCapabilities: id=%lu", oec_session_id_); + LOGV("Getting analog output capabilities: id = %u", oec_session_id_); uint32_t flags; WithOecReadLock("GetAnalogOutputCapabilities", [&] { flags = OEMCrypto_GetAnalogOutputFlags(requested_security_level_); @@ -2795,7 +2761,7 @@ void CryptoSession::IncrementIV(uint64_t increase_by, template auto CryptoSession::WithStaticFieldWriteLock(const char* tag, Func body) -> decltype(body()) { - LOGV("Static Field Write Lock - %s", tag); + LOGV("Static field write lock: %s", tag); std::unique_lock auto_lock(static_field_mutex_); return body(); } @@ -2803,7 +2769,7 @@ auto CryptoSession::WithStaticFieldWriteLock(const char* tag, Func body) template auto CryptoSession::WithStaticFieldReadLock(const char* tag, Func body) -> decltype(body()) { - LOGV("Static Field Read Lock - %s", tag); + LOGV("Static field read lock: %s", tag); shared_lock auto_lock(static_field_mutex_); return body(); } @@ -2811,7 +2777,7 @@ auto CryptoSession::WithStaticFieldReadLock(const char* tag, Func body) template auto CryptoSession::WithOecWriteLock(const char* tag, Func body) -> decltype(body()) { - LOGV("OEMCrypto Write Lock - %s", tag); + LOGV("OEMCrypto write lock: %s", tag); std::unique_lock auto_lock(oem_crypto_mutex_); return body(); } @@ -2819,7 +2785,7 @@ auto CryptoSession::WithOecWriteLock(const char* tag, Func body) template auto CryptoSession::WithOecReadLock(const char* tag, Func body) -> decltype(body()) { - LOGV("OEMCrypto Read Lock - %s", tag); + LOGV("OEMCrypto read lock: %s", tag); shared_lock auto_lock(oem_crypto_mutex_); return body(); } @@ -2827,7 +2793,7 @@ auto CryptoSession::WithOecReadLock(const char* tag, Func body) template auto CryptoSession::WithOecSessionLock(const char* tag, Func body) -> decltype(body()) { - LOGV("OEMCrypto Session Lock - %s", tag); + LOGV("OEMCrypto session lock: %s", tag); shared_lock oec_auto_lock(oem_crypto_mutex_); std::unique_lock session_auto_lock(oem_crypto_session_mutex_); return body(); diff --git a/libwvdrmengine/cdm/core/src/device_files.cpp b/libwvdrmengine/cdm/core/src/device_files.cpp index 1d59c8e4..c3911035 100644 --- a/libwvdrmengine/cdm/core/src/device_files.cpp +++ b/libwvdrmengine/cdm/core/src/device_files.cpp @@ -40,11 +40,34 @@ using video_widevine_client::sdk:: using video_widevine::DrmDeviceCertificate; using video_widevine::SignedDrmDeviceCertificate; -#define RETURN_FALSE_IF_NULL(PARAM) \ - if (PARAM == nullptr) { \ - LOGE("|PARAM| not provided"); \ - *result = kParameterNull; \ - return false; \ +// Stringify turns macro arguments into static C strings. +// Example: STRINGIFY(this_argument) -> "this_argument" +#define STRINGIFY(PARAM...) #PARAM + +#define RETURN_FALSE_IF_NULL(PARAM) \ + if ((PARAM) == nullptr) { \ + LOGE("Output parameter |" STRINGIFY(PARAM) "| not provided"); \ + return false; \ + } + +#define RETURN_FALSE_WITH_RESULT_IF_NULL(PARAM, result) \ + if ((PARAM) == nullptr) { \ + LOGE("Output parameter |" STRINGIFY(PARAM) "| not provided"); \ + *result = kParameterNull; \ + return false; \ + } + +#define RETURN_FALSE_IF_UNINITIALIZED() \ + if (!initialized_) { \ + LOGE("Device files is not initialized"); \ + return false; \ + } + +#define RETURN_FALSE_WITH_RESULT_IF_UNINITIALIZED(result) \ + if (!initialized_) { \ + LOGE("Device files is not initialized"); \ + *result = kObjectNotInitialized; \ + return false; \ } namespace { @@ -74,13 +97,13 @@ DeviceFiles::~DeviceFiles() {} bool DeviceFiles::Init(CdmSecurityLevel security_level) { if (!file_system_) { - LOGD("DeviceFiles::Init: Invalid FileSystem given."); + LOGE("Invalid FileSystem given"); return false; } std::string path; if (!Properties::GetDeviceFilesBasePath(security_level, &path)) { - LOGW("DeviceFiles::Init: Unsupported security level %d", security_level); + LOGE("Unsupported security level: %d", security_level); return false; } security_level_ = security_level; @@ -90,10 +113,7 @@ bool DeviceFiles::Init(CdmSecurityLevel security_level) { bool DeviceFiles::StoreCertificate(const std::string& certificate, const std::string& wrapped_private_key) { - if (!initialized_) { - LOGW("DeviceFiles::StoreCertificate: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); // Fill in file information video_widevine_client::sdk::File file; @@ -116,29 +136,28 @@ bool DeviceFiles::RetrieveCertificate(std::string* certificate, std::string* wrapped_private_key, std::string* serial_number, uint32_t* system_id) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveCertificate: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; if (RetrieveHashedFile(GetCertificateFileName(), &file) != kNoError) { - LOGW("DeviceFiles::RetrieveCertificate: unable to retrieve file"); + LOGE("Unable to retrieve certificate file"); return false; } if (file.type() != video_widevine_client::sdk::File::DEVICE_CERTIFICATE) { - LOGW("DeviceFiles::RetrieveCertificate: Incorrect file type"); + LOGE("Certificate file is of incorrect file type: type = %d", + static_cast(file.type())); return false; } if (file.version() != video_widevine_client::sdk::File::VERSION_1) { - LOGW("DeviceFiles::RetrieveCertificate: Incorrect file version"); + LOGE("Certificate file is of incorrect file version: version = %d", + static_cast(file.version())); return false; } if (!file.has_device_certificate()) { - LOGW("DeviceFiles::RetrieveCertificate: Certificate not present"); + LOGE("Certificate not present"); return false; } @@ -152,9 +171,9 @@ bool DeviceFiles::RetrieveCertificate(std::string* certificate, bool DeviceFiles::ExtractDeviceInfo(const std::string& device_certificate, std::string* serial_number, uint32_t* system_id) { - LOGI("ExtractDeviceInfo Entry"); - if (!serial_number && !system_id) { - LOGE("DeviceFiles::ExtractDeviceInfo: invalid parameter."); + LOGV("Extracting device info"); + if (serial_number == nullptr && system_id == nullptr) { + LOGE("Output parameters |serial_number| and |system_id| not provided"); return false; } @@ -162,9 +181,7 @@ bool DeviceFiles::ExtractDeviceInfo(const std::string& device_certificate, SignedDrmDeviceCertificate signed_drm_device_certificate; if (!signed_drm_device_certificate.ParseFromString(device_certificate) || !signed_drm_device_certificate.has_drm_certificate()) { - LOGE( - "DeviceFiles::ExtractDeviceInfo: fails parsing signed drm device " - "certificate."); + LOGE("Failed to parse signed DRM device certificate"); return false; } DrmDeviceCertificate drm_device_certificate; @@ -172,9 +189,7 @@ bool DeviceFiles::ExtractDeviceInfo(const std::string& device_certificate, signed_drm_device_certificate.drm_certificate()) || (drm_device_certificate.type() != video_widevine::DrmDeviceCertificate::DRM_USER_DEVICE)) { - LOGE( - "DeviceFiles::ExtractDeviceInfo: fails parsing drm device " - "certificate message."); + LOGE("Failed to parse DRM device certificate message"); return false; } if (serial_number != NULL) { @@ -187,20 +202,12 @@ bool DeviceFiles::ExtractDeviceInfo(const std::string& device_certificate, } bool DeviceFiles::HasCertificate() { - if (!initialized_) { - LOGW("DeviceFiles::HasCertificate: not initialized"); - return false; - } - + RETURN_FALSE_IF_UNINITIALIZED(); return FileExists(GetCertificateFileName()); } bool DeviceFiles::RemoveCertificate() { - if (!initialized_) { - LOGW("DeviceFiles::RemoveCertificate: not initialized"); - return false; - } - + RETURN_FALSE_IF_UNINITIALIZED() return RemoveFile(GetCertificateFileName()); } @@ -214,18 +221,10 @@ bool DeviceFiles::StoreLicense( int64_t last_playback_time, int64_t grace_period_end_time, const CdmAppParameterMap& app_parameters, const CdmUsageEntry& usage_entry, const uint32_t usage_entry_number, ResponseType* result) { - if (result == nullptr) { - LOGE("DeviceFiles::StoreLicense: |result| not provided"); - return false; - } + RETURN_FALSE_IF_NULL(result); *result = kNoError; - - if (!initialized_) { - LOGW("DeviceFiles::StoreLicense: not initialized"); - *result = kObjectNotInitialized; - return false; - } + RETURN_FALSE_WITH_RESULT_IF_UNINITIALIZED(result); // Fill in file information video_widevine_client::sdk::File file; @@ -242,7 +241,7 @@ bool DeviceFiles::StoreLicense( license->set_state(License_LicenseState_RELEASING); break; default: - LOGW("DeviceFiles::StoreLicense: Unknown license state: %u", state); + LOGE("Unknown license state: %d", static_cast(state)); *result = kUnknownLicenseState; return false; break; @@ -283,52 +282,54 @@ bool DeviceFiles::RetrieveLicense( int64_t* last_playback_time, int64_t* grace_period_end_time, CdmAppParameterMap* app_parameters, CdmUsageEntry* usage_entry, uint32_t* usage_entry_number, ResponseType* result) { + // This check must be made first as the RETURN_FALSE_IF_NULL() macro + // will assign NULL_PARAMETER to |result|. if (result == nullptr) { - LOGE("DeviceFiles::RetrieveLicense: |result| not provided"); + LOGE("Output parameter |result| not provided"); return false; } + RETURN_FALSE_WITH_RESULT_IF_UNINITIALIZED(result); - if (!initialized_) { - LOGW("DeviceFiles::RetrieveLicense: not initialized"); - *result = kObjectNotInitialized; - return false; - } - - RETURN_FALSE_IF_NULL(state); - RETURN_FALSE_IF_NULL(pssh_data); - RETURN_FALSE_IF_NULL(license_request); - RETURN_FALSE_IF_NULL(license_message); - RETURN_FALSE_IF_NULL(license_renewal_request); - RETURN_FALSE_IF_NULL(license_renewal); - RETURN_FALSE_IF_NULL(release_server_url); - RETURN_FALSE_IF_NULL(playback_start_time); - RETURN_FALSE_IF_NULL(last_playback_time); - RETURN_FALSE_IF_NULL(grace_period_end_time); - RETURN_FALSE_IF_NULL(app_parameters); - RETURN_FALSE_IF_NULL(usage_entry); - RETURN_FALSE_IF_NULL(usage_entry_number); + RETURN_FALSE_WITH_RESULT_IF_NULL(state, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(pssh_data, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(license_request, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(license_message, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(license_renewal_request, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(license_renewal, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(release_server_url, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(playback_start_time, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(last_playback_time, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(grace_period_end_time, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(app_parameters, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(usage_entry, result); + RETURN_FALSE_WITH_RESULT_IF_NULL(usage_entry_number, result); video_widevine_client::sdk::File file; *result = RetrieveHashedFile(key_set_id + kLicenseFileNameExt, &file); if (*result != kNoError) { - LOGW("DeviceFiles::RetrieveLicense: unable to retrieve file: %d", *result); + LOGE("Unable to retrieve key set license file: result = %d", + static_cast(*result)); return false; } if (file.type() != video_widevine_client::sdk::File::LICENSE) { - LOGW("DeviceFiles::RetrieveLicense: Incorrect file type"); + LOGE("Incorrect file type: type = %d, expected_type = %d", + static_cast(file.type()), + static_cast(video_widevine_client::sdk::File::LICENSE)); *result = kIncorrectFileType; return false; } if (file.version() != video_widevine_client::sdk::File::VERSION_1) { - LOGW("DeviceFiles::RetrieveLicense: Incorrect file version"); + LOGE("Incorrect file version: version = %d, expected_version = %d", + static_cast(file.version()), + static_cast(video_widevine_client::sdk::File::VERSION_1)); *result = kIncorrectFileVersion; return false; } if (!file.has_license()) { - LOGW("DeviceFiles::RetrieveLicense: License not present"); + LOGE("License not present"); *result = kLicenseNotPresent; return false; } @@ -343,8 +344,7 @@ bool DeviceFiles::RetrieveLicense( *state = kLicenseStateReleasing; break; default: - LOGW("DeviceFiles::RetrieveLicense: Unrecognized license state: %u", - kLicenseStateUnknown); + LOGW("Unrecognized license state: %d", static_cast(license.state())); *state = kLicenseStateUnknown; break; } @@ -367,23 +367,13 @@ bool DeviceFiles::RetrieveLicense( } bool DeviceFiles::DeleteLicense(const std::string& key_set_id) { - if (!initialized_) { - LOGW("DeviceFiles::DeleteLicense: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); return RemoveFile(key_set_id + kLicenseFileNameExt); } bool DeviceFiles::ListLicenses(std::vector* key_set_ids) { - if (!initialized_) { - LOGW("DeviceFiles::ListLicenses: not initialized"); - return false; - } - - if (key_set_ids == NULL) { - LOGW("DeviceFiles::ListLicenses: key_set_ids parameter not provided"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(key_set_ids); // Get list of filenames std::vector filenames; @@ -408,47 +398,31 @@ bool DeviceFiles::ListLicenses(std::vector* key_set_ids) { } bool DeviceFiles::DeleteAllLicenses() { - if (!initialized_) { - LOGW("DeviceFiles::DeleteAllLicenses: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); return RemoveFile(std::string(kWildcard) + kLicenseFileNameExt); } bool DeviceFiles::DeleteAllFiles() { - if (!initialized_) { - LOGW("DeviceFiles::DeleteAllFiles: not initialized"); - return false; - } - + RETURN_FALSE_IF_UNINITIALIZED(); // We pass an empty string to RemoveFile to delete the device files base // directory itself. return RemoveFile(kEmptyFileName); } bool DeviceFiles::LicenseExists(const std::string& key_set_id) { - if (!initialized_) { - LOGW("DeviceFiles::LicenseExists: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); return reserved_license_ids_.count(key_set_id) || FileExists(key_set_id + kLicenseFileNameExt); } bool DeviceFiles::ReserveLicenseId(const std::string& key_set_id) { - if (!initialized_) { - LOGW("DeviceFiles::ReserveLicenseId: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); reserved_license_ids_.insert(key_set_id); return true; } bool DeviceFiles::UnreserveLicenseId(const std::string& key_set_id) { - if (!initialized_) { - LOGW("DeviceFiles::UnreserveLicenseId: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); reserved_license_ids_.erase(key_set_id); return true; } @@ -460,18 +434,14 @@ bool DeviceFiles::StoreUsageInfo(const std::string& provider_session_token, const std::string& key_set_id, const std::string& usage_entry, uint32_t usage_entry_number) { - if (!initialized_) { - LOGW("DeviceFiles::StoreUsageInfo: not initialized"); - return false; - } - + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; if (!FileExists(usage_info_file_name)) { file.set_type(video_widevine_client::sdk::File::USAGE_INFO); file.set_version(video_widevine_client::sdk::File::VERSION_1); } else { if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::StoreUsageInfo: Unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } } @@ -495,40 +465,39 @@ bool DeviceFiles::StoreUsageInfo(const std::string& provider_session_token, bool DeviceFiles::ListUsageIds( const std::string& app_id, std::vector* ksids, std::vector* provider_session_tokens) { - if (!initialized_) { - LOGW("DeviceFiles::ListUsageIds: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); - if (ksids == NULL && provider_session_tokens == NULL) { - LOGW("DeviceFiles::ListUsageIds: ksids or pst parameter not provided"); + if (ksids == nullptr && provider_session_tokens == nullptr) { + LOGE( + "Both output parameters |ksids| and |provider_session_tokens| are " + "not provided"); return false; } // Empty or non-existent file == no usage records. std::string file_name = GetUsageInfoFileName(app_id); if (!FileExists(file_name) || GetFileSize(file_name) == 0) { - if (ksids != NULL) ksids->clear(); - if (provider_session_tokens != NULL) provider_session_tokens->clear(); + if (ksids != nullptr) ksids->clear(); + if (provider_session_tokens != nullptr) provider_session_tokens->clear(); return true; } video_widevine_client::sdk::File file; if (RetrieveHashedFile(file_name, &file) != kNoError) { - LOGW("DeviceFiles::ListUsageRecords: Unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } - if (ksids != NULL) ksids->clear(); - if (provider_session_tokens != NULL) provider_session_tokens->clear(); + if (ksids != nullptr) ksids->clear(); + if (provider_session_tokens != nullptr) provider_session_tokens->clear(); size_t num_records = file.usage_info().sessions_size(); for (size_t i = 0; i < num_records; ++i) { - if ((ksids != NULL) && + if ((ksids != nullptr) && !file.usage_info().sessions(i).key_set_id().empty()) { ksids->push_back(file.usage_info().sessions(i).key_set_id()); } - if ((provider_session_tokens != NULL) && + if ((provider_session_tokens != nullptr) && !file.usage_info().sessions(i).token().empty()) { provider_session_tokens->push_back(file.usage_info().sessions(i).token()); } @@ -539,25 +508,18 @@ bool DeviceFiles::ListUsageIds( bool DeviceFiles::GetProviderSessionToken(const std::string& app_id, const std::string& key_set_id, std::string* provider_session_token) { - if (!initialized_) { - LOGW("DeviceFiles::GetProviderSessionToken: not initialized"); - return false; - } - - if (provider_session_token == NULL) { - LOGW("DeviceFiles::GetProviderSessionToken: NULL return argument pointer"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(provider_session_token); std::string file_name = GetUsageInfoFileName(app_id); if (!FileExists(file_name) || GetFileSize(file_name) == 0) { - LOGW("DeviceFiles::GetProviderSessionToken: empty file"); + LOGE("Usage info file does not exists or is an empty file"); return false; } video_widevine_client::sdk::File file; if (RetrieveHashedFile(file_name, &file) != kNoError) { - LOGW("DeviceFiles::GetProviderSessionToken: unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -573,13 +535,10 @@ bool DeviceFiles::GetProviderSessionToken(const std::string& app_id, bool DeviceFiles::DeleteUsageInfo(const std::string& usage_info_file_name, const std::string& provider_session_token) { - if (!initialized_) { - LOGW("DeviceFiles::DeleteUsageInfo: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::DeleteUsageInfo: Unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -594,10 +553,8 @@ bool DeviceFiles::DeleteUsageInfo(const std::string& usage_info_file_name, } if (!found) { - LOGW( - "DeviceFiles::DeleteUsageInfo: Unable to find provider session " - "token: %s", - b2a_hex(provider_session_token).c_str()); + LOGE("Unable to find provider session token: pst = %s", + b2a_hex(provider_session_token).c_str()); return false; } @@ -616,14 +573,9 @@ bool DeviceFiles::DeleteUsageInfo(const std::string& usage_info_file_name, bool DeviceFiles::DeleteAllUsageInfoForApp( const std::string& usage_info_file_name, std::vector* provider_session_tokens) { - if (!initialized_) { - LOGW("DeviceFiles::DeleteAllUsageInfoForApp: not initialized"); - return false; - } - if (NULL == provider_session_tokens) { - LOGW("DeviceFiles::DeleteAllUsageInfoForApp: pst destination not provided"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(provider_session_tokens); + provider_session_tokens->clear(); if (!FileExists(usage_info_file_name)) return true; @@ -634,16 +586,13 @@ bool DeviceFiles::DeleteAllUsageInfoForApp( provider_session_tokens->push_back(file.usage_info().sessions(i).token()); } } else { - LOGW("DeviceFiles::DeleteAllUsageInfoForApp: Unable to retrieve file"); + LOGW("Unable to retrieve usage info file"); } return RemoveFile(usage_info_file_name); } bool DeviceFiles::DeleteAllUsageInfo() { - if (!initialized_) { - LOGW("DeviceFiles::DeleteAllUsageInfo: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); return RemoveFile(kUsageInfoFileNamePrefix + std::string(kWildcard) + kUsageInfoFileNameExt); } @@ -651,17 +600,8 @@ bool DeviceFiles::DeleteAllUsageInfo() { bool DeviceFiles::RetrieveUsageInfo( const std::string& usage_info_file_name, std::vector >* usage_info) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveUsageInfo: not initialized"); - return false; - } - - if (NULL == usage_info) { - LOGW( - "DeviceFiles::RetrieveUsageInfo: license destination not " - "provided"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(usage_info); if (!FileExists(usage_info_file_name) || GetFileSize(usage_info_file_name) == 0) { @@ -671,7 +611,7 @@ bool DeviceFiles::RetrieveUsageInfo( video_widevine_client::sdk::File file; if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::RetrieveUsageInfo: Unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -691,14 +631,11 @@ bool DeviceFiles::RetrieveUsageInfo(const std::string& usage_info_file_name, CdmKeyResponse* license_response, std::string* usage_entry, uint32_t* usage_entry_number) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveUsageInfo: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::RetrieveUsageInfo: unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -722,14 +659,11 @@ bool DeviceFiles::RetrieveUsageInfoByKeySetId( std::string* provider_session_token, CdmKeyMessage* license_request, CdmKeyResponse* license_response, std::string* usage_entry, uint32_t* usage_entry_number) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveUsageInfoByKeySetId: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::RetrieveUsageInfoByKeySetId: unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -751,10 +685,7 @@ bool DeviceFiles::RetrieveUsageInfoByKeySetId( bool DeviceFiles::StoreUsageInfo(const std::string& usage_info_file_name, const std::vector& usage_data) { - if (!initialized_) { - LOGW("DeviceFiles::StoreUsageInfo: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; file.set_type(video_widevine_client::sdk::File::USAGE_INFO); @@ -784,19 +715,16 @@ bool DeviceFiles::StoreUsageInfo(const std::string& usage_info_file_name, bool DeviceFiles::UpdateUsageInfo(const std::string& usage_info_file_name, const std::string& provider_session_token, const CdmUsageData& usage_data) { - if (!initialized_) { - LOGW("DeviceFiles::UpdateUsageInfo: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; if (!FileExists(usage_info_file_name)) { - LOGW("DeviceFiles::UpdateUsageInfo: Usage file does not exist"); + LOGE("Usage info file does not exist"); return false; } if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::UpdateUsageInfo: Unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -824,15 +752,8 @@ bool DeviceFiles::UpdateUsageInfo(const std::string& usage_info_file_name, bool DeviceFiles::RetrieveUsageInfo(const std::string& usage_info_file_name, std::vector* usage_data) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveUsageInfo: not initialized"); - return false; - } - - if (usage_data == NULL) { - LOGW("DeviceFiles::RetrieveUsageInfo: usage_data not provided"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(usage_data); if (!FileExists(usage_info_file_name) || GetFileSize(usage_info_file_name) == 0) { @@ -842,7 +763,7 @@ bool DeviceFiles::RetrieveUsageInfo(const std::string& usage_info_file_name, video_widevine_client::sdk::File file; if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::RetrieveUsageInfo: unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -865,19 +786,12 @@ bool DeviceFiles::RetrieveUsageInfo(const std::string& usage_info_file_name, bool DeviceFiles::RetrieveUsageInfo(const std::string& usage_info_file_name, const std::string& provider_session_token, CdmUsageData* usage_data) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveUsageInfo: not initialized"); - return false; - } - - if (usage_data == NULL) { - LOGW("DeviceFiles::RetrieveUsageInfo: usage_data not provided"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(usage_data); video_widevine_client::sdk::File file; if (RetrieveHashedFile(usage_info_file_name, &file) != kNoError) { - LOGW("DeviceFiles::RetrieveUsageInfo: unable to retrieve file"); + LOGE("Unable to retrieve usage info file"); return false; } @@ -902,15 +816,8 @@ bool DeviceFiles::RetrieveUsageInfo(const std::string& usage_info_file_name, bool DeviceFiles::ListUsageInfoFiles( std::vector* usage_info_file_names) { - if (!initialized_) { - LOGW("DeviceFiles::ListUsageInfoFiles: not initialized"); - return false; - } - - if (usage_info_file_names == NULL) { - LOGW("DeviceFiles::ListUsageInfoFiles: usage_info_file_names not provided"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(usage_info_file_names); // Get list of filenames std::vector filenames; @@ -937,10 +844,7 @@ bool DeviceFiles::ListUsageInfoFiles( bool DeviceFiles::StoreHlsAttributes( const std::string& key_set_id, const CdmHlsMethod method, const std::vector& media_segment_iv) { - if (!initialized_) { - LOGW("DeviceFiles::StoreHlsAttributes: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); // Fill in file information video_widevine_client::sdk::File file; @@ -958,8 +862,7 @@ bool DeviceFiles::StoreHlsAttributes( break; case kHlsMethodNone: default: - LOGW("DeviceFiles::StoreHlsAttributeInfo: Unknown HLS method: %u", - method); + LOGE("Unknown HLS method: %d", method); return false; break; } @@ -976,32 +879,28 @@ bool DeviceFiles::StoreHlsAttributes( bool DeviceFiles::RetrieveHlsAttributes( const std::string& key_set_id, CdmHlsMethod* method, std::vector* media_segment_iv) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveHlsAttributes: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); video_widevine_client::sdk::File file; if (RetrieveHashedFile(key_set_id + kHlsAttributesFileNameExt, &file) != kNoError) { - LOGW("DeviceFiles::RetrieveHlsAttributes: unable to retrieve file"); + LOGE("Unable to retrieve key set HLS attributes file"); return false; } if (file.type() != video_widevine_client::sdk::File::HLS_ATTRIBUTES) { - LOGW("DeviceFiles::RetrieveHlsAttributes: Incorrect file type: %u", - file.type()); + LOGE("Incorrect file type: type = %d", static_cast(file.type())); return false; } if (file.version() != video_widevine_client::sdk::File::VERSION_1) { - LOGW("DeviceFiles::RetrieveHlsAttributes: Incorrect file version: %u", - file.version()); + LOGE("Incorrect file version: version = %d", + static_cast(file.version())); return false; } if (!file.has_hls_attributes()) { - LOGW("DeviceFiles::RetrieveHlsAttributes: HLS attributes not present"); + LOGE("HLS attributes not present"); return false; } @@ -1015,8 +914,8 @@ bool DeviceFiles::RetrieveHlsAttributes( *method = kHlsMethodSampleAes; break; default: - LOGW("DeviceFiles::RetrieveHlsAttributes: Unrecognized HLS method: %u", - attributes.method()); + LOGW("Unrecognized HLS method: %d", + static_cast(attributes.method())); *method = kHlsMethodNone; break; } @@ -1026,20 +925,14 @@ bool DeviceFiles::RetrieveHlsAttributes( } bool DeviceFiles::DeleteHlsAttributes(const std::string& key_set_id) { - if (!initialized_) { - LOGW("DeviceFiles::DeleteHlsAttributes: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); return RemoveFile(key_set_id + kHlsAttributesFileNameExt); } bool DeviceFiles::StoreUsageTableInfo( const CdmUsageTableHeader& usage_table_header, const std::vector& usage_entry_info) { - if (!initialized_) { - LOGW("DeviceFiles::StoreUsageTableInfo: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); // Fill in file information video_widevine_client::sdk::File file; @@ -1082,40 +975,32 @@ bool DeviceFiles::StoreUsageTableInfo( bool DeviceFiles::RetrieveUsageTableInfo( CdmUsageTableHeader* usage_table_header, std::vector* usage_entry_info) { - if (!initialized_) { - LOGW("DeviceFiles::RetrieveUsageTableInfo: not initialized"); - return false; - } - - if (usage_table_header == NULL) { - LOGW( - "DeviceFiles::RetrieveUsageTableInfo: usage_table_header not provided"); - return false; - } - - if (usage_entry_info == NULL) { - LOGW("DeviceFiles::RetrieveUsageTableInfo: usage_entry_info not provided"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); + RETURN_FALSE_IF_NULL(usage_table_header); + RETURN_FALSE_IF_NULL(usage_entry_info); video_widevine_client::sdk::File file; if (RetrieveHashedFile(GetUsageTableFileName(), &file) != kNoError) { - LOGW("DeviceFiles::RetrieveUsageTableInfo: unable to retrieve file"); + LOGE("Unable to retrieve usage table file"); return false; } if (file.type() != video_widevine_client::sdk::File::USAGE_TABLE_INFO) { - LOGW("DeviceFiles::RetrieveUsageTableInfo: Incorrect file type"); + LOGE("Incorrect file type: type = %d, expected_type = %d", + static_cast(file.type()), + static_cast(video_widevine_client::sdk::File::USAGE_TABLE_INFO)); return false; } if (file.version() != video_widevine_client::sdk::File::VERSION_1) { - LOGW("DeviceFiles::RetrieveUsageTableInfo: Incorrect file version"); + LOGE("Incorrect file version: version = %d, expected_version = %d", + static_cast(file.version()), + static_cast(video_widevine_client::sdk::File::VERSION_1)); return false; } if (!file.has_usage_table_info()) { - LOGW("DeviceFiles::RetrieveUsageTableInfo: Usage table info not present"); + LOGE("Usage table info not present in file"); return false; } @@ -1147,10 +1032,7 @@ bool DeviceFiles::RetrieveUsageTableInfo( } bool DeviceFiles::DeleteUsageTableInfo() { - if (!initialized_) { - LOGW("DeviceFiles::DeleteUsageTableInfo: not initialized"); - return false; - } + RETURN_FALSE_IF_UNINITIALIZED(); return RemoveFile(GetUsageTableFileName()); } @@ -1173,7 +1055,7 @@ DeviceFiles::ResponseType DeviceFiles::StoreFileRaw( const std::string& name, const std::string& serialized_file) { std::string path; if (!Properties::GetDeviceFilesBasePath(security_level_, &path)) { - LOGW("DeviceFiles::StoreFileRaw: Unable to get base path"); + LOGE("Unable to get base path"); return kBasePathUnavailable; } @@ -1182,21 +1064,26 @@ DeviceFiles::ResponseType DeviceFiles::StoreFileRaw( auto file = file_system_->Open(path, FileSystem::kCreate | FileSystem::kTruncate); if (!file) { - LOGW("DeviceFiles::StoreFileRaw: File open failed: %s", path.c_str()); + LOGE("Failed to open file: path = %s", path.c_str()); return kFileOpenFailed; } - ssize_t bytes = file->Write(serialized_file.data(), serialized_file.size()); + const ssize_t bytes_written = + file->Write(serialized_file.data(), serialized_file.size()); - if (bytes != static_cast(serialized_file.size())) { - LOGW( - "DeviceFiles::StoreFileRaw: write failed: (actual: %d, " - "expected: %d)", - bytes, serialized_file.size()); + if (bytes_written < 0) { + LOGE("Failed to write to file: path = %s", path.c_str()); + return kFileWriteError; + } + if (bytes_written != static_cast(serialized_file.size())) { + LOGE( + "Failed to fully write to file: path = %s, " + "bytes_written = %zd, bytes_attempted = %zu", + path.c_str(), bytes_written, serialized_file.size()); return kFileWriteError; } - LOGV("DeviceFiles::StoreFileRaw: success: %s (%db)", path.c_str(), + LOGV("Successfully stored raw file: path = %s, size = %zu", path.c_str(), serialized_file.size()); return kNoError; } @@ -1206,28 +1093,27 @@ DeviceFiles::ResponseType DeviceFiles::RetrieveHashedFile( video_widevine_client::sdk::File* deserialized_file) { std::string serialized_file; - if (!deserialized_file) { - LOGW("DeviceFiles::RetrieveHashedFile: Unspecified file parameter"); + if (deserialized_file == nullptr) { + LOGE("File handle parameter |deserialized_file| not provided"); return kParameterNull; } std::string path; if (!Properties::GetDeviceFilesBasePath(security_level_, &path)) { - LOGW("DeviceFiles::RetrieveHashedFile: Unable to get base path"); + LOGE("Unable to get base path"); return kBasePathUnavailable; } path += name; if (!file_system_->Exists(path)) { - LOGW("DeviceFiles::RetrieveHashedFile: %s does not exist", path.c_str()); + LOGE("File does not exist: path = %s", path.c_str()); return kFileNotFound; } - ssize_t bytes = file_system_->FileSize(path); - if (bytes <= 0) { - LOGW("DeviceFiles::RetrieveHashedFile: File size invalid: %s", - path.c_str()); + const ssize_t file_size = file_system_->FileSize(path); + if (file_size <= 0) { + LOGE("File size is invalid: %s", path.c_str()); // Remove the corrupted file so the caller will not get the same error // when trying to access the file repeatedly, causing the system to stall. file_system_->Remove(path); @@ -1240,23 +1126,31 @@ DeviceFiles::ResponseType DeviceFiles::RetrieveHashedFile( } std::string serialized_hash_file; - serialized_hash_file.resize(bytes); - bytes = file->Read(&serialized_hash_file[0], serialized_hash_file.size()); + serialized_hash_file.resize(file_size); + const ssize_t bytes_read = + file->Read(&serialized_hash_file[0], serialized_hash_file.size()); - if (bytes != static_cast(serialized_hash_file.size())) { - LOGW("DeviceFiles::RetrieveHashedFile: read failed: %d", bytes); + if (bytes_read != file_size) { + if (bytes_read < 0) { + LOGE("Failed to read from file: path = %s", path.c_str()); + } else { + LOGE( + "Failed to fully read from file: " + "path = %s, bytes_read = %zd, bytes_attempted = %zd", + path.c_str(), bytes_read, file_size); + } // Remove the corrupted file so the caller will not get the same error // when trying to access the file repeatedly, causing the system to stall. file_system_->Remove(path); return kFileReadError; } - LOGV("DeviceFiles::RetrieveHashedFile: success: %s (%db)", path.c_str(), + LOGV("Successfully read file: path = %s, size = %zu", path.c_str(), serialized_hash_file.size()); HashedFile hash_file; if (!hash_file.ParseFromString(serialized_hash_file)) { - LOGW("DeviceFiles::RetrieveHashedFile: Unable to parse hash file"); + LOGE("Unable to parse hash file"); // Remove the corrupted file so the caller will not get the same error // when trying to access the file repeatedly, causing the system to stall. file_system_->Remove(path); @@ -1265,7 +1159,7 @@ DeviceFiles::ResponseType DeviceFiles::RetrieveHashedFile( std::string hash = Sha256Hash(hash_file.file()); if (hash != hash_file.hash()) { - LOGW("DeviceFiles::RetrieveHashedFile: Hash mismatch"); + LOGE("File hash mismatch: path = %s", path.c_str()); // Remove the corrupted file so the caller will not get the same error // when trying to access the file repeatedly, causing the system to stall. file_system_->Remove(path); @@ -1273,7 +1167,7 @@ DeviceFiles::ResponseType DeviceFiles::RetrieveHashedFile( } if (!deserialized_file->ParseFromString(hash_file.file())) { - LOGW("DeviceFiles::RetrieveHashedFile: Unable to parse file"); + LOGE("Unable to parse hashed file"); // Remove the corrupted file so the caller will not get the same error // when trying to access the file repeatedly, causing the system to stall. file_system_->Remove(path); @@ -1285,7 +1179,7 @@ DeviceFiles::ResponseType DeviceFiles::RetrieveHashedFile( bool DeviceFiles::FileExists(const std::string& name) { std::string path; if (!Properties::GetDeviceFilesBasePath(security_level_, &path)) { - LOGW("DeviceFiles::FileExists: Unable to get base path"); + LOGE("Unable to get base path"); return false; } path += name; @@ -1296,7 +1190,7 @@ bool DeviceFiles::FileExists(const std::string& name) { bool DeviceFiles::ListFiles(std::vector* names) { std::string path; if (!Properties::GetDeviceFilesBasePath(security_level_, &path)) { - LOGW("DeviceFiles::ListFiles: Unable to get base path"); + LOGE("Unable to get base path"); return false; } return file_system_->List(path, names); @@ -1305,7 +1199,7 @@ bool DeviceFiles::ListFiles(std::vector* names) { bool DeviceFiles::RemoveFile(const std::string& name) { std::string path; if (!Properties::GetDeviceFilesBasePath(security_level_, &path)) { - LOGW("DeviceFiles::RemoveFile: Unable to get base path"); + LOGE("Unable to get base path"); return false; } path += name; @@ -1316,7 +1210,7 @@ bool DeviceFiles::RemoveFile(const std::string& name) { ssize_t DeviceFiles::GetFileSize(const std::string& name) { std::string path; if (!Properties::GetDeviceFilesBasePath(security_level_, &path)) { - LOGW("DeviceFiles::GetFileSize: Unable to get base path"); + LOGE("Unable to get base path"); return -1; } path += name; diff --git a/libwvdrmengine/cdm/core/src/entitlement_key_session.cpp b/libwvdrmengine/cdm/core/src/entitlement_key_session.cpp index 82eea314..d48e3573 100644 --- a/libwvdrmengine/cdm/core/src/entitlement_key_session.cpp +++ b/libwvdrmengine/cdm/core/src/entitlement_key_session.cpp @@ -45,7 +45,7 @@ OEMCryptoResult EntitlementKeySession::LoadEntitledContentKeys( OEMCryptoResult EntitlementKeySession::SelectKey(const std::string& key_id, CdmCipherMode cipher_mode) { if (entitled_keys_.find(key_id) == entitled_keys_.end()) { - LOGE("Unknown entitled key ID selected."); + LOGE("Unknown entitled key ID selected"); return OEMCrypto_ERROR_NO_CONTENT_KEY; } @@ -68,7 +68,8 @@ OEMCryptoResult EntitlementKeySession::SelectKey(const std::string& key_id, message.size(), 1, &entitled_key), metrics_, oemcrypto_load_entitled_keys_, result); if (result != OEMCrypto_SUCCESS) { - LOGE("SelectKey: OEMCrypto_LoadEntitledContentKeys error=%d", result); + LOGE("OEMCrypto_LoadEntitledContentKeys failed: status = %d", + static_cast(result)); return result; } diff --git a/libwvdrmengine/cdm/core/src/initialization_data.cpp b/libwvdrmengine/cdm/core/src/initialization_data.cpp index 8969583f..31db68e7 100644 --- a/libwvdrmengine/cdm/core/src/initialization_data.cpp +++ b/libwvdrmengine/cdm/core/src/initialization_data.cpp @@ -76,9 +76,7 @@ InitializationData::InitializationData(const std::string& type, if (is_cenc()) { bool oec_prefers_entitlements = DetectEntitlementPreference(oec_version); if (!SelectWidevinePssh(data, oec_prefers_entitlements, &data_)) { - LOGE( - "InitializationData: Unable to select a supported Widevine PSSH " - "from the init data."); + LOGE("Unable to select a supported Widevine PSSH from the init data"); } } else if (is_webm()) { data_ = data; @@ -115,15 +113,11 @@ bool InitializationData::SelectWidevinePssh(const CdmInitData& init_data, // Extract the data payloads from the Widevine PSSHs. std::vector pssh_payloads; if (!ExtractWidevinePsshs(init_data, &pssh_payloads)) { - LOGE( - "InitializationData::SelectWidevinePssh: Unable to parse concatenated " - "PSSH boxes."); + LOGE("Unable to parse concatenated PSSH boxes"); return false; } if (pssh_payloads.empty()) { - LOGE( - "InitializationData::SelectWidevinePssh: The concatenated PSSH boxes " - "could be parsed, but no Widevine PSSH was found."); + LOGE("Widevine PSSH was not found in concatenated PSSH boxes"); return false; } @@ -133,10 +127,7 @@ bool InitializationData::SelectWidevinePssh(const CdmInitData& init_data, for (size_t i = 0; i < pssh_payloads.size(); ++i) { WidevinePsshData pssh; if (!pssh.ParseFromString(pssh_payloads[i])) { - LOGE( - "InitializationData::SelectWidevinePssh: Unable to parse PSSH data " - "%lu into a protobuf.", - i); + LOGE("Unable to parse PSSH data into a protobuf: index = %zu", i); continue; } if (pssh.type() == WidevinePsshData_Type_ENTITLED_KEY) { @@ -168,8 +159,8 @@ bool InitializationData::SelectWidevinePssh(const CdmInitData& init_data, bool InitializationData::ExtractWidevinePsshs(const CdmInitData& init_data, std::vector* psshs) { - if (psshs == NULL) { - LOGE("InitializationData::ExtractWidevinePsshs: NULL psshs parameter"); + if (psshs == nullptr) { + LOGE("Output parameter |psshs| not provided"); return false; } psshs->clear(); @@ -180,23 +171,23 @@ bool InitializationData::ExtractWidevinePsshs(const CdmInitData& init_data, BufferReader reader(data_start, init_data.length()); while (!reader.IsEOF()) { + // LOGV is used intentionally as it is expected that the CDM will try + // several PSSHs until it finds the correct one. + // See b/23419359 for more information. + const size_t start_pos = reader.pos(); // Atom size. Used for bounding the inner reader and knowing how far to skip // forward after parsing this PSSH. uint64_t size; if (!reader.Read4Into8(&size)) { - LOGV( - "InitializationData::ExtractWidevinePsshs: Unable to read the " - "32-bit atom size."); + LOGV("Unable to read the 32-bit atom size"); return false; // We cannot continue reading safely. Abort. } // Skip the atom type for now. if (!reader.SkipBytes(4)) { - LOGV( - "InitializationData::ExtractWidevinePsshs: Unable to skip the " - "atom type."); + LOGV("Unable to skip the atom type"); return false; // We cannot continue reading safely. Abort. } @@ -204,9 +195,7 @@ bool InitializationData::ExtractWidevinePsshs(const CdmInitData& init_data, // An "atom size" of 1 means the real atom size is a 64-bit number stored // after the atom type. if (!reader.Read8(&size)) { - LOGV( - "InitializationData::ExtractWidevinePsshs: Unable to read the " - "64-bit atom size."); + LOGV("Unable to read the 64-bit atom size"); return false; // We cannot continue reading safely. Abort. } } else if (size == 0) { @@ -219,8 +208,8 @@ bool InitializationData::ExtractWidevinePsshs(const CdmInitData& init_data, if (!reader.HasBytes(bytes_remaining)) { LOGV( - "InitializationData::ExtractWidevinePsshs: Invalid atom size. The " - "atom claims to be larger than the remaining init data."); + "Invalid atom size: The atom claims to be larger than the " + "remaining init data"); return false; // We cannot continue reading safely. Abort. } @@ -233,9 +222,7 @@ bool InitializationData::ExtractWidevinePsshs(const CdmInitData& init_data, // Skip past the rest of the atom. if (!reader.SkipBytes(bytes_remaining)) { - LOGV( - "InitializationData::LocateWidevinePsshOffsets: Unable to skip the " - "rest of the atom."); + LOGV("Unable to skip the rest of the atom"); return false; // We cannot continue reading safely. Abort. } } @@ -249,15 +236,16 @@ bool InitializationData::ExtractWidevinePsshs(const CdmInitData& init_data, bool InitializationData::ExtractWidevinePsshData(const uint8_t* data, size_t length, CdmInitData* output) { + // LOGV is used intentionally as it is expected that the CDM will try + // several PSSHs until it finds the correct one. + // See b/23419359 for more information. BufferReader reader(data, length); // Read the 32-bit size only so we can check if we need to expect a 64-bit // size. uint64_t size_32; if (!reader.Read4Into8(&size_32)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to read the " - "32-bit atom size."); + LOGV("Unable to read the 32-bit atom size"); return false; } const bool has_size_64 = (size_32 == 1); @@ -265,22 +253,18 @@ bool InitializationData::ExtractWidevinePsshData(const uint8_t* data, // Read the atom type and check that it is "pssh". std::vector atom_type; if (!reader.ReadVec(&atom_type, 4)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to read the atom " - "type."); + LOGV("Unable to read the atom type"); return false; } if (memcmp(&atom_type[0], "pssh", 4) != 0) { - LOGV("InitializationData::ExtractWidevinePsshData: Atom type is not PSSH."); + LOGV("Atom type is not PSSH"); return false; } // If there is a 64-bit size, skip it. if (has_size_64) { if (!reader.SkipBytes(8)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to skip the " - "64-bit atom size."); + LOGV("Unable to skip the 64-bit atom size"); return false; } } @@ -288,39 +272,29 @@ bool InitializationData::ExtractWidevinePsshData(const uint8_t* data, // Read the version number and abort if it is not one we can handle. uint8_t version; if (!reader.Read1(&version)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to read the PSSH " - "version."); + LOGV("Unable to read the PSSH version"); return false; } if (version > 1) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unrecognized PSSH " - "version."); + LOGV("Unrecognized PSSH version: %d", static_cast(version)); return false; } // Skip the flags. if (!reader.SkipBytes(3)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to skip the PSSH " - "flags."); + LOGV("Unable to skip the PSSH flags"); return false; } // Read the System ID and validate that it is the Widevine System ID. std::vector system_id; if (!reader.ReadVec(&system_id, sizeof(kWidevineSystemId))) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to read the " - "system ID."); + LOGV("Unable to read the system ID"); return false; } if (memcmp(&system_id[0], kWidevineSystemId, sizeof(kWidevineSystemId)) != 0) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Found a non-Widevine " - "PSSH."); + LOGV("Found a non-Widevine PSSH"); return false; } @@ -329,17 +303,13 @@ bool InitializationData::ExtractWidevinePsshData(const uint8_t* data, // Read the number of key IDs so we know how far to skip ahead. uint32_t num_key_ids; if (!reader.Read4(&num_key_ids)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to read the " - "number of key IDs."); + LOGV("Unable to read the number of key IDs"); return false; } // Skip the key IDs. if (!reader.SkipBytes(num_key_ids * 16)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to skip the key " - "IDs."); + LOGV("Unable to skip the key IDs"); return false; } } @@ -347,18 +317,14 @@ bool InitializationData::ExtractWidevinePsshData(const uint8_t* data, // Read the size of the PSSH data. uint32_t data_length; if (!reader.Read4(&data_length)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to read the PSSH " - "data size."); + LOGV("Unable to read the PSSH data size"); return false; } // Read the PSSH data. output->clear(); if (!reader.ReadString(output, data_length)) { - LOGV( - "InitializationData::ExtractWidevinePsshData: Unable to read the PSSH " - "data."); + LOGV("Unable to read the PSSH data"); return false; } @@ -383,20 +349,18 @@ bool InitializationData::ExtractHlsAttributes(const std::string& attribute_list, CdmHlsMethod* method, std::vector* iv, std::string* uri) { + // LOGV is used intentionally as it is expected that the CDM will try + // several PSSHs until it finds the correct one. + // See b/23419359 for more information. std::string value; if (!ExtractQuotedAttribute(attribute_list, HLS_KEYFORMAT_ATTRIBUTE, &value)) { - LOGV( - "InitializationData::ExtractHlsInitDataAtttribute: Unable to read HLS " - "keyformat value"); + LOGV("Unable to read HLS 'keyformat' value"); return false; } if (value.compare(0, sizeof(KEY_SYSTEM) - 1, KEY_SYSTEM) != 0) { - LOGV( - "InitializationData::ExtractHlsInitDataAtttribute: unrecognized HLS " - "keyformat value: %s", - value.c_str()); + LOGV("Unrecognized HLS 'keyformat' value: %s", value.c_str()); return false; } @@ -413,18 +377,14 @@ bool InitializationData::ExtractHlsAttributes(const std::string& attribute_list, } } if (!supported) { - LOGV( - "InitializationData::ExtractHlsInitDataAtttribute: HLS keyformat " - "version is not supported: %s", - value.c_str()); + LOGV("HLS 'keyformat' version is not supported: value = %s", + value.c_str()); return false; } } if (!ExtractAttribute(attribute_list, HLS_METHOD_ATTRIBUTE, &value)) { - LOGV( - "InitializationData::ExtractHlsInitDataAtttribute: Unable to read HLS " - "method"); + LOGV("Unable to read HLS method"); return false; } @@ -435,24 +395,17 @@ bool InitializationData::ExtractHlsAttributes(const std::string& attribute_list, } else if (value.compare(HLS_METHOD_NONE) == 0) { *method = kHlsMethodNone; } else { - LOGV( - "InitializationData::ExtractHlsInitDataAtttribute: HLS method " - "unrecognized: %s", - value.c_str()); + LOGV("HLS method unrecognized: value = %s", value.c_str()); return false; } if (!ExtractHexAttribute(attribute_list, HLS_IV_ATTRIBUTE, iv)) { - LOGV( - "InitializationData::ExtractHlsInitDataAtttribute: HLS IV attribute " - "not present"); + LOGV("HLS IV attribute not present"); return false; } if (!ExtractQuotedAttribute(attribute_list, HLS_URI_ATTRIBUTE, uri)) { - LOGV( - "InitializationData::ExtractHlsInitDataAtttribute: HLS URI attribute " - "not present"); + LOGV("HLS URI attribute not present"); return false; } @@ -476,31 +429,27 @@ bool InitializationData::ExtractHlsAttributes(const std::string& attribute_list, bool InitializationData::ConstructWidevineInitData( CdmHlsMethod method, const std::string& uri, CdmInitData* init_data_proto) { if (!init_data_proto) { - LOGV("InitializationData::ConstructWidevineInitData: Invalid parameter"); + LOGE("Output parameter |init_data_proto| not provided"); return false; } if (method != kHlsMethodAes128 && method != kHlsMethodSampleAes) { - LOGV( - "InitializationData::ConstructWidevineInitData: Invalid method" - " parameter"); + LOGE("Invalid HLS method parameter"); return false; } + // LOGV is used intentionally as it is expected that the CDM will try + // several PSSHs until it finds the correct one. + // See b/23419359 for more information. size_t pos = uri.find(kBase64String); if (pos == std::string::npos) { - LOGV( - "InitializationData::ConstructWidevineInitData: URI attribute " - "unexpected format: %s", - uri.c_str()); + LOGV("URI attribute unexpected format: uri = %s", uri.c_str()); return false; } std::vector json_init_data = Base64Decode(uri.substr(pos + kBase64String.size())); if (json_init_data.size() == 0) { - LOGV( - "InitializationData::ConstructWidevineInitData: Base64 decode of json " - "data failed"); + LOGV("Base64 decode of json data failed"); return false; } std::string json_string((const char*)(&json_init_data[0]), @@ -515,10 +464,7 @@ bool InitializationData::ConstructWidevineInitData( kDefaultNumJsonTokens); if (num_of_tokens <= 0) { - LOGV( - "InitializationData::ConstructWidevineInitData: Json parsing failed: " - "%d", - num_of_tokens); + LOGV("Json parsing failed: num_of_tokens = %d", num_of_tokens); return false; } @@ -538,9 +484,7 @@ bool InitializationData::ConstructWidevineInitData( // Extract the provider, content_id and key_ids for (int i = 0; i < num_of_tokens; ++i) { if (tokens[i].start < 0 || tokens[i].end < 0) { - LOGV( - "InitializationData::ConstructWidevineInitData: Invalid start or end " - "of token"); + LOGV("Invalid start and/or end of token"); return false; } @@ -593,17 +537,17 @@ bool InitializationData::ConstructWidevineInitData( } if (provider.size() == 0) { - LOGV("InitializationData::ConstructWidevineInitData: Invalid provider"); + LOGV("Invalid provider"); return false; } if (content_id.size() == 0) { - LOGV("InitializationData::ConstructWidevineInitData: Invalid content_id"); + LOGV("Invalid content ID"); return false; } if (key_ids.size() == 0) { - LOGV("InitializationData::ConstructWidevineInitData: No key_ids present"); + LOGV("No key IDs present"); return false; } diff --git a/libwvdrmengine/cdm/core/src/license.cpp b/libwvdrmengine/cdm/core/src/license.cpp index d7dcd761..c0b7cbd3 100644 --- a/libwvdrmengine/cdm/core/src/license.cpp +++ b/libwvdrmengine/cdm/core/src/license.cpp @@ -176,8 +176,8 @@ static std::vector ExtractContentKeys(const License& license) { } CdmLicense::CdmLicense(const CdmSessionId& session_id) - : crypto_session_(NULL), - policy_engine_(NULL), + : crypto_session_(nullptr), + policy_engine_(nullptr), session_id_(session_id), initialized_(false), renew_with_client_id_(false), @@ -187,8 +187,8 @@ CdmLicense::CdmLicense(const CdmSessionId& session_id) license_key_type_(kLicenseKeyTypeContent) {} CdmLicense::CdmLicense(const CdmSessionId& session_id, Clock* clock) - : crypto_session_(NULL), - policy_engine_(NULL), + : crypto_session_(nullptr), + policy_engine_(nullptr), session_id_(session_id), initialized_(false), renew_with_client_id_(false), @@ -205,24 +205,24 @@ bool CdmLicense::Init(const std::string& client_token, const std::string& device_id, bool use_privacy_mode, const std::string& signed_service_certificate, CryptoSession* session, PolicyEngine* policy_engine) { - if (clock_.get() == NULL) { - LOGE("CdmLicense::Init: clock parameter not provided"); + if (clock_.get() == nullptr) { + LOGE("Clock parameter not provided"); return false; } if (session_id_.empty()) { - LOGE("CdmLicense::Init: empty session id provided"); + LOGE("Session ID not provided"); return false; } if (client_token.size() == 0) { - LOGE("CdmLicense::Init: empty client token provided"); + LOGE("Client token not provided"); return false; } - if (session == NULL || !session->IsOpen()) { - LOGE("CdmLicense::Init: crypto session not provided or not open"); + if (session == nullptr || !session->IsOpen()) { + LOGE("Crypto session not provided or not open"); return false; } - if (policy_engine == NULL) { - LOGE("CdmLicense::Init: no policy engine provided"); + if (policy_engine == nullptr) { + LOGE("Policy engine not provided"); return false; } @@ -233,7 +233,7 @@ bool CdmLicense::Init(const std::string& client_token, } if (!service_certificate_.has_certificate() && !Properties::allow_service_certificate_requests()) { - LOGE("CdmLicense::Init: Required service certificate not provided"); + LOGE("Required service certificate not provided"); return false; } } @@ -253,7 +253,7 @@ CdmResponseType CdmLicense::PrepareKeyRequest( const CdmAppParameterMap& app_parameters, CdmKeyMessage* signed_request, std::string* server_url) { if (!initialized_) { - LOGE("CdmLicense::PrepareKeyRequest: not initialized"); + LOGE("CdmLicense not initialized"); return LICENSE_PARSER_NOT_INITIALIZED_4; } if (init_data.IsEmpty() && stored_init_data_.get()) { @@ -264,20 +264,19 @@ CdmResponseType CdmLicense::PrepareKeyRequest( } wrapped_keys_ = init_data.ExtractWrappedKeys(); if (!init_data.is_supported()) { - LOGE("CdmLicense::PrepareKeyRequest: unsupported init data type (%s)", - init_data.type().c_str()); + LOGE("Unsupported init data type: type = %s", init_data.type().c_str()); return INVALID_PARAMETERS_LIC_3; } if (init_data.IsEmpty()) { - LOGE("CdmLicense::PrepareKeyRequest: empty init data provided"); + LOGE("Init data is empty"); return INVALID_PARAMETERS_LIC_4; } - if (!signed_request) { - LOGE("CdmLicense::PrepareKeyRequest: no signed request provided"); + if (signed_request == nullptr) { + LOGE("Output parameter |signed_request| not provided"); return INVALID_PARAMETERS_LIC_6; } - if (!server_url) { - LOGE("CdmLicense::PrepareKeyRequest: no server url provided"); + if (server_url == nullptr) { + LOGE("Output parameter |server_url| not provided"); return INVALID_PARAMETERS_LIC_7; } @@ -285,18 +284,14 @@ CdmResponseType CdmLicense::PrepareKeyRequest( // configuration, request service certificate or declare error if (use_privacy_mode_ && !service_certificate_.has_certificate()) { if (!Properties::allow_service_certificate_requests()) { - LOGE( - "CdmLicense::PrepareKeyRequest: failure with privacy mode - " - "no service certificate."); + LOGE("Privacy mode failure: No service certificate"); return PRIVACY_MODE_ERROR_1; } stored_init_data_.reset(new InitializationData(init_data)); if (!ServiceCertificate::GetRequest(signed_request)) { - LOGE( - "CdmLicense::PrepareKeyRequest: failed to prepare a service " - "certificated request"); + LOGE("Failed to prepare service certificated request"); return LICENSE_REQUEST_SERVICE_CERTIFICATE_GENERATION_ERROR; } @@ -333,7 +328,7 @@ CdmResponseType CdmLicense::PrepareKeyRequest( return LICENSE_REQUEST_NONCE_GENERATION_ERROR; } license_request.set_key_control_nonce(nonce); - LOGD("PrepareKeyRequest: nonce=%u", nonce); + LOGD("nonce = %u", nonce); license_request.set_protocol_version(video_widevine::VERSION_2_1); @@ -354,7 +349,7 @@ CdmResponseType CdmLicense::PrepareKeyRequest( } if (license_request_signature.empty()) { - LOGE("CdmLicense::PrepareKeyRequest: License request signature empty"); + LOGE("License request signature is empty"); signed_request->clear(); return EMPTY_LICENSE_REQUEST; } @@ -376,28 +371,26 @@ CdmResponseType CdmLicense::PrepareKeyUpdateRequest( CdmSession* cdm_session, CdmKeyMessage* signed_request, std::string* server_url) { if (!initialized_) { - LOGE("CdmLicense::PrepareKeyUpdateRequest: not initialized"); + LOGE("CdmLicense not initialized"); return LICENSE_PARSER_NOT_INITIALIZED_1; } - if (!signed_request) { - LOGE("CdmLicense::PrepareKeyUpdateRequest: No signed request provided"); + if (signed_request == nullptr) { + LOGE("Output parameter |signed_request| not provided"); return INVALID_PARAMETERS_LIC_1; } - if (!server_url) { - LOGE("CdmLicense::PrepareKeyUpdateRequest: No server url provided"); + if (server_url == nullptr) { + LOGE("Output parameter |server_url| not provided"); return INVALID_PARAMETERS_LIC_2; } if (is_renewal && !policy_engine_->CanRenew()) { - LOGE("CdmLicense::PrepareKeyUpdateRequest: license renewal prohibited"); + LOGE("License renewal prohibited"); return LICENSE_RENEWAL_PROHIBITED; } if (renew_with_client_id_) { if (use_privacy_mode_ && !service_certificate_.has_certificate()) { - LOGE( - "CdmLicense::PrepareKeyUpdateRequest: failure with privacy mode - " - "no service certificate."); + LOGE("Privacy mode failure: No service certificate"); return PRIVACY_MODE_ERROR_2; } } @@ -476,7 +469,7 @@ CdmResponseType CdmLicense::PrepareKeyUpdateRequest( return LICENSE_RENEWAL_NONCE_GENERATION_ERROR; } license_request.set_key_control_nonce(nonce); - LOGD("PrepareKeyUpdateRequest: nonce=%u", nonce); + LOGD("nonce = %u", nonce); license_request.set_protocol_version(video_widevine::VERSION_2_1); // License request is complete. Serialize it. @@ -490,9 +483,7 @@ CdmResponseType CdmLicense::PrepareKeyUpdateRequest( if (status != NO_ERROR) return status; if (license_request_signature.empty()) { - LOGE( - "CdmLicense::PrepareKeyUpdateRequest: empty license request" - " signature"); + LOGE("License request signature is empty"); return EMPTY_LICENSE_RENEWAL; } @@ -510,22 +501,20 @@ CdmResponseType CdmLicense::PrepareKeyUpdateRequest( CdmResponseType CdmLicense::HandleKeyResponse( const CdmKeyResponse& license_response) { if (!initialized_) { - LOGE("CdmLicense::HandleKeyResponse: not initialized"); + LOGE("CdmLicense not initialized"); return LICENSE_PARSER_NOT_INITIALIZED_2; } // Clear the latest service version when we receive a new response. latest_service_version_.Clear(); if (license_response.empty()) { - LOGE("CdmLicense::HandleKeyResponse: empty license response"); + LOGE("License response is empty"); return EMPTY_LICENSE_RESPONSE_1; } SignedMessage signed_response; if (!signed_response.ParseFromString(license_response)) { - LOGE( - "CdmLicense::HandleKeyResponse: unable to parse signed license" - " response"); + LOGE("Unable to parse signed license response"); return INVALID_LICENSE_RESPONSE; } @@ -546,24 +535,24 @@ CdmResponseType CdmLicense::HandleKeyResponse( return HandleKeyErrorResponse(signed_response); if (signed_response.type() != SignedMessage::LICENSE) { - LOGE("CdmLicense::HandleKeyResponse: unrecognized signed message type: %d", - signed_response.type()); + LOGE("Unrecognized signed message type: type = %d", + static_cast(signed_response.type())); return INVALID_LICENSE_TYPE; } if (!signed_response.has_signature()) { - LOGE("CdmLicense::HandleKeyResponse: license response is not signed"); + LOGE("License response is not signed"); return LICENSE_RESPONSE_NOT_SIGNED; } License license; if (!license.ParseFromString(signed_response.msg())) { - LOGE("CdmLicense::HandleKeyResponse: unable to parse license response"); + LOGE("Unable to parse license response"); return LICENSE_RESPONSE_PARSE_ERROR_1; } if (!signed_response.has_session_key()) { - LOGE("CdmLicense::HandleKeyResponse: no session keys present"); + LOGE("Signed response has no session keys present"); return SESSION_KEYS_NOT_FOUND; } CdmResponseType status = crypto_session_->GenerateDerivedKeys( @@ -587,8 +576,8 @@ CdmResponseType CdmLicense::HandleKeyResponse( if (mac_key_iv.size() != KEY_IV_SIZE || mac_keys.size() != 2 * MAC_KEY_SIZE) { LOGE( - "CdmLicense::HandleKeyResponse: mac key/iv size error" - "(key/iv size expected: %d/%d, actual: %d/%d", + "MAC key/IV size error: expected = %lu/%lu, " + "actual = %zu/%zu (key/iv)", 2 * MAC_KEY_SIZE, KEY_IV_SIZE, mac_keys.size(), mac_key_iv.size()); return KEY_SIZE_ERROR_1; } @@ -601,7 +590,7 @@ CdmResponseType CdmLicense::HandleKeyResponse( key_type = kLicenseKeyTypeContent; } if (key_array.empty()) { - LOGE("CdmLicense::HandleKeyResponse : No content keys."); + LOGE("No content keys"); return NO_CONTENT_KEY; } license_key_type_ = key_type; @@ -628,9 +617,9 @@ CdmResponseType CdmLicense::HandleKeyResponse( if (license.id().has_provider_session_token()) provider_session_token_ = license.id().provider_session_token(); - LOGV("provider_session_token: %s", provider_session_token_.empty() - ? "N/A" - : provider_session_token_.c_str()); + LOGV("provider_session_token = %s", provider_session_token_.empty() + ? "N/A" + : provider_session_token_.c_str()); if (license.policy().has_renewal_server_url()) { server_url_ = license.policy().renewal_server_url(); @@ -656,19 +645,17 @@ CdmResponseType CdmLicense::HandleKeyResponse( CdmResponseType CdmLicense::HandleKeyUpdateResponse( bool is_renewal, const CdmKeyResponse& license_response) { if (!initialized_) { - LOGE("CdmLicense::HandleKeyUpdateResponse: not initialized"); + LOGE("CdmLicense not initialized"); return LICENSE_PARSER_NOT_INITIALIZED_3; } if (license_response.empty()) { - LOGE("CdmLicense::HandleKeyUpdateResponse : Empty license response."); + LOGE("License response is empty"); return EMPTY_LICENSE_RESPONSE_2; } SignedMessage signed_response; if (!signed_response.ParseFromString(license_response)) { - LOGE( - "CdmLicense::HandleKeyUpdateResponse: Unable to parse signed " - "message"); + LOGE("Unable to parse signed message"); return LICENSE_RESPONSE_PARSE_ERROR_2; } @@ -678,28 +665,24 @@ CdmResponseType CdmLicense::HandleKeyUpdateResponse( case SignedMessage::ERROR_RESPONSE: return HandleKeyErrorResponse(signed_response); default: - LOGE( - "CdmLicense::HandleKeyUpdateResponse: unrecognized signed message " - "type: %d", - signed_response.type()); + LOGE("Unrecognized signed message type: type = %d", + static_cast(signed_response.type())); return INVALID_LICENSE_TYPE; } if (!signed_response.has_signature()) { - LOGE("CdmLicense::HandleKeyUpdateResponse: signature missing"); + LOGE("Update key response is missing signature"); return SIGNATURE_NOT_FOUND; } License license; if (!license.ParseFromString(signed_response.msg())) { - LOGE( - "CdmLicense::HandleKeyUpdateResponse: Unable to parse license" - " from signed message"); + LOGE("Unable to parse license from signed message"); return LICENSE_RESPONSE_PARSE_ERROR_3; } if (!license.has_id()) { - LOGE("CdmLicense::HandleKeyUpdateResponse: license id not present"); + LOGE("License ID not present"); return LICENSE_ID_NOT_FOUND; } @@ -747,38 +730,35 @@ CdmResponseType CdmLicense::RestoreOfflineLicense( int64_t last_playback_time, int64_t grace_period_end_time, CdmSession* cdm_session) { if (license_request.empty()) { - LOGE("CdmLicense::RestoreOfflineLicense: empty |license_request|"); + LOGE("License request is empty"); return EMPTY_LICENSE_REQUEST_2; } if (license_response.empty()) { - LOGE("CdmLicense::RestoreOfflineLicense: empty |license_response|"); + LOGE("License response is empty"); return EMPTY_LICENSE_RESPONSE_3; } SignedMessage signed_request; if (!signed_request.ParseFromString(license_request)) { - LOGE("CdmLicense::RestoreOfflineLicense: |license_request| parse failed"); + LOGE("Failed to parse license request"); return PARSE_REQUEST_ERROR_1; } if (signed_request.type() != SignedMessage::LICENSE_REQUEST) { - LOGE( - "CdmLicense::RestoreOfflineLicense: license request type: expected = " - "%d, actual = %d", - SignedMessage::LICENSE_REQUEST, signed_request.type()); + LOGE("Unexpected license request type: expected = %d, actual = %d", + static_cast(SignedMessage::LICENSE_REQUEST), + static_cast(signed_request.type())); return INVALID_LICENSE_REQUEST_TYPE_1; } key_request_ = signed_request.msg(); - CdmResponseType sts = HandleKeyResponse(license_response); if (sts != KEY_ADDED) return sts; if (!license_renewal_response.empty()) { sts = HandleKeyUpdateResponse(true, license_renewal_response); - if (sts != KEY_ADDED) return sts; } @@ -827,27 +807,25 @@ CdmResponseType CdmLicense::RestoreLicenseForRelease( const CdmKeyMessage& license_request, const CdmKeyResponse& license_response) { if (license_request.empty()) { - LOGE("CdmLicense::RestoreLicenseForRelease: empty |license_request|"); + LOGE("License request is empty"); return EMPTY_LICENSE_REQUEST_3; } if (license_response.empty()) { - LOGE("CdmLicense::RestoreLicenseForRelease: empty |license_response|"); + LOGE("License response is empty"); return EMPTY_LICENSE_RESPONSE_4; } SignedMessage signed_request; if (!signed_request.ParseFromString(license_request)) { - LOGE("CdmLicense::RestoreLicenseForRelease: license_request parse failed"); + LOGE("Failed to parse signed license request"); return PARSE_REQUEST_ERROR_2; } if (signed_request.type() != SignedMessage::LICENSE_REQUEST) { - LOGE( - "CdmLicense::RestoreLicenseForRelease: license request type: " - "expected " - "= %d, actual = %d", - SignedMessage::LICENSE_REQUEST, signed_request.type()); + LOGE("Unexpected signed license request type: expected = %d, actual = %d", + static_cast(SignedMessage::LICENSE_REQUEST), + static_cast(signed_request.type())); return INVALID_LICENSE_REQUEST_TYPE_2; } @@ -855,32 +833,25 @@ CdmResponseType CdmLicense::RestoreLicenseForRelease( SignedMessage signed_response; if (!signed_response.ParseFromString(license_response)) { - LOGE( - "CdmLicense::RestoreLicenseForRelease: unable to parse signed license" - " response"); + LOGE("Failed to parse signed license response"); return LICENSE_RESPONSE_PARSE_ERROR_4; } if (SignedMessage::LICENSE != signed_response.type()) { - LOGE( - "CdmLicense::RestoreLicenseForRelease: unrecognized signed message " - "type: %d", - signed_response.type()); + LOGE("Unexpected signed license response type: expected = %d, actual = %d", + static_cast(SignedMessage::LICENSE), + static_cast(signed_response.type())); return INVALID_LICENSE_TYPE_2; } if (!signed_response.has_signature()) { - LOGE( - "CdmLicense::RestoreLicenseForRelease: license response is not" - " signed"); + LOGE("License response is not signed"); return SIGNATURE_NOT_FOUND_2; } License license; if (!license.ParseFromString(signed_response.msg())) { - LOGE( - "CdmLicense::RestoreLicenseForRelease: unable to parse license" - " response"); + LOGE("Failed to parse license response"); return LICENSE_RESPONSE_PARSE_ERROR_5; } @@ -894,7 +865,7 @@ CdmResponseType CdmLicense::RestoreLicenseForRelease( renew_with_client_id_ = license.policy().always_include_client_id(); if (!signed_response.has_session_key()) { - LOGE("CdmLicense::RestoreLicenseForRelease: no session keys present"); + LOGE("No session keys present"); return SESSION_KEYS_NOT_FOUND_2; } @@ -920,31 +891,26 @@ bool CdmLicense::ExtractProviderSessionToken( const CdmKeyResponse& license_response, std::string* provider_session_token) { if (license_response.empty()) { - LOGE("CdmLicense::ExtractProviderSessionToken: empty license response"); + LOGE("License response is empty"); return false; } SignedMessage signed_response; if (!signed_response.ParseFromString(license_response)) { - LOGE( - "CdmLicense::ExtractProviderSessionToken: unable to parse signed " - "license response"); + LOGE("Failed to parse signed license response"); return false; } if (signed_response.type() != SignedMessage::LICENSE) { - LOGE( - "CdmLicense::ExtractProviderSessionToken: unrecognized signed message " - "type: %d", - signed_response.type()); + LOGE("Unexpected signed license response type: expected = %d, actual = %d", + static_cast(SignedMessage::LICENSE), + static_cast(signed_response.type())); return false; } License license; if (!license.ParseFromString(signed_response.msg())) { - LOGE( - "CdmLicense::ExtractProviderSessionToken: unable to parse license " - "response"); + LOGE("Failed to parse license response"); return false; } @@ -961,7 +927,7 @@ CdmResponseType CdmLicense::HandleKeyErrorResponse( const SignedMessage& signed_message) { LicenseError license_error; if (!license_error.ParseFromString(signed_message.msg())) { - LOGE("CdmLicense::HandleKeyErrorResponse: Unable to parse license error"); + LOGE("Failed to parse license error response"); return KEY_ERROR; } @@ -972,8 +938,8 @@ CdmResponseType CdmLicense::HandleKeyErrorResponse( return DEVICE_REVOKED; case LicenseError::SERVICE_UNAVAILABLE: default: - LOGW("CdmLicense::HandleKeyErrorResponse: Unknown error type = %d", - license_error.error_code()); + LOGW("Unknown error type: error_code = %d", + static_cast(license_error.error_code())); return KEY_ERROR; } } @@ -992,7 +958,7 @@ CdmResponseType CdmLicense::PrepareClientId( if (Properties::UsePrivacyMode(session_id_)) { if (!service_certificate_.has_certificate()) { - LOGE("CdmLicense::PrepareClientId: Service Certificate not staged"); + LOGE("Service certificate not staged"); return PRIVACY_MODE_ERROR_3; } EncryptedClientIdentification* encrypted_client_id = @@ -1023,7 +989,7 @@ CdmResponseType CdmLicense::PrepareContentId( if (!init_data.IsEmpty()) { cenc_content_id->add_pssh(init_data.data()); } else { - LOGE("CdmLicense::PrepareContentId: ISO-CENC init data not available"); + LOGE("ISO-CENC init data not available"); return CENC_INIT_DATA_UNAVAILABLE; } @@ -1037,7 +1003,7 @@ CdmResponseType CdmLicense::PrepareContentId( if (!init_data.IsEmpty()) { webm_content_id->set_header(init_data.data()); } else { - LOGE("CdmLicense::PrepareContentId: WebM init data not available"); + LOGE("WebM init data not available"); return WEBM_INIT_DATA_UNAVAILABLE; } @@ -1045,8 +1011,7 @@ CdmResponseType CdmLicense::PrepareContentId( return PREPARE_WEBM_CONTENT_ID_FAILED; } } else { - LOGE("CdmLicense::PrepareContentId: no support for init data type (%s)", - init_data.type().c_str()); + LOGE("Unsupported init data type: type = %s", init_data.type().c_str()); return UNSUPPORTED_INIT_DATA_FORMAT; } return NO_ERROR; @@ -1058,7 +1023,7 @@ CdmResponseType CdmLicense::HandleContentKeyResponse( const std::vector& key_array, const video_widevine::License& license) { if (key_array.empty()) { - LOGE("CdmLicense::HandleKeyResponse : No content keys."); + LOGE("No content keys provided"); return NO_CONTENT_KEY; } CdmResponseType resp = crypto_session_->LoadKeys( @@ -1082,7 +1047,7 @@ CdmResponseType CdmLicense::HandleEntitlementKeyResponse( const std::vector& key_array, const video_widevine::License& license) { if (key_array.empty()) { - LOGE("CdmLicense::HandleKeyResponse : No entitlement keys."); + LOGE("No entitlement keys provided"); return NO_CONTENT_KEY; } CdmResponseType resp = crypto_session_->LoadKeys( @@ -1120,7 +1085,10 @@ CdmResponseType CdmLicense::HandleNewEntitledKeys( // Strip PKCS#5 padding from entitled content keys. std::string content_key = wk->key(); if (content_key.size() < CONTENT_KEY_SIZE) { - LOGE("Entitled Key too small, %lu bytes", content_key.size()); + LOGE( + "Entitled content key too small: " + "expected = %lu, actual = %zu (bytes)", + CONTENT_KEY_SIZE, content_key.size()); return KEY_SIZE_ERROR_2; } else if (content_key.size() > CONTENT_KEY_SIZE) { content_key.resize(CONTENT_KEY_SIZE); @@ -1161,8 +1129,7 @@ bool CdmLicense::SetTypeAndId(CdmLicenseType license_type, content_id->set_license_type(video_widevine::STREAMING); break; default: - LOGD("CdmLicense::PrepareKeyRequest: Unknown license type = %d", - license_type); + LOGD("Unknown license type: %d", static_cast(license_type)); return false; } diff --git a/libwvdrmengine/cdm/core/src/license_key_status.cpp b/libwvdrmengine/cdm/core/src/license_key_status.cpp index ec8240dc..d404492a 100644 --- a/libwvdrmengine/cdm/core/src/license_key_status.cpp +++ b/libwvdrmengine/cdm/core/src/license_key_status.cpp @@ -37,10 +37,8 @@ wvcdm::CryptoSession::HdcpCapability ProtobufHdcpToOemCryptoHdcp( case OutputProtection::HDCP_NO_DIGITAL_OUTPUT: return HDCP_NO_DIGITAL_OUTPUT; default: - LOGE( - "ContentKeyStatus::ProtobufHdcpToOemCryptoHdcp: " - "Unknown HDCP Level: input=%d, returning HDCP_NO_DIGITAL_OUTPUT", - input); + LOGE("Unknown HDCP Level, returning HDCP_NO_DIGITAL_OUTPUT: input = %d", + static_cast(input)); return HDCP_NO_DIGITAL_OUTPUT; } } @@ -60,7 +58,7 @@ VideoResolutionConstraint* GetConstraintForRes( return constraint; } } - return NULL; + return nullptr; } } // namespace @@ -327,7 +325,7 @@ bool LicenseKeyStatus::CanDecryptContent() { } bool LicenseKeyStatus::GetAllowedUsage(CdmKeyAllowedUsage* allowed_usage) { - if (NULL == allowed_usage) return false; + if (allowed_usage == nullptr) return false; *allowed_usage = allowed_usage_; return true; } @@ -363,10 +361,10 @@ bool LicenseKeyStatus::ApplyStatusChange(CdmKeyStatus new_status, // device's current HDCP level. void LicenseKeyStatus::ApplyConstraints( uint32_t video_pixels, CryptoSession::HdcpCapability new_hdcp_level) { - VideoResolutionConstraint* current_constraint = NULL; + VideoResolutionConstraint* current_constraint = nullptr; if (HasConstraints() && video_pixels != HDCP_UNSPECIFIED_VIDEO_RESOLUTION) { current_constraint = GetConstraintForRes(video_pixels, constraints_); - if (NULL == current_constraint) { + if (current_constraint == nullptr) { meets_constraints_ = false; return; } diff --git a/libwvdrmengine/cdm/core/src/policy_engine.cpp b/libwvdrmengine/cdm/core/src/policy_engine.cpp index 54c281d5..28d23b0a 100644 --- a/libwvdrmengine/cdm/core/src/policy_engine.cpp +++ b/libwvdrmengine/cdm/core/src/policy_engine.cpp @@ -52,7 +52,7 @@ bool PolicyEngine::CanDecryptContent(const KeyId& key_id) { if (license_keys_->IsContentKey(key_id)) { return license_keys_->CanDecryptContent(key_id); } else { - LOGE("PolicyEngine::CanDecryptContent Key '%s' not in license.", + LOGE("Provided content key is not in license: key_id = %s", b2a_hex(key_id).c_str()); return false; } @@ -192,7 +192,7 @@ void PolicyEngine::UpdateLicense(const License& license) { if (!license.has_policy()) return; if (kLicenseStateExpired == license_state_) { - LOGD("PolicyEngine::UpdateLicense: updating an expired license"); + LOGD("Updating an expired license"); } policy_.MergeFrom(license.policy()); @@ -299,8 +299,8 @@ CdmResponseType PolicyEngine::Query(CdmQueryMap* query_response) { CdmResponseType PolicyEngine::QueryKeyAllowedUsage( const KeyId& key_id, CdmKeyAllowedUsage* key_usage) { - if (NULL == key_usage) { - LOGE("PolicyEngine::QueryKeyAllowedUsage: no key_usage provided"); + if (key_usage == nullptr) { + LOGE("Output parameter |key_usage| not provided"); return PARAMETER_NULL; } if (license_keys_->GetAllowedUsage(key_id, key_usage)) { diff --git a/libwvdrmengine/cdm/core/src/privacy_crypto_boringssl.cpp b/libwvdrmengine/cdm/core/src/privacy_crypto_boringssl.cpp index ec9b58b1..e7635d26 100644 --- a/libwvdrmengine/cdm/core/src/privacy_crypto_boringssl.cpp +++ b/libwvdrmengine/cdm/core/src/privacy_crypto_boringssl.cpp @@ -7,9 +7,7 @@ // for signature verification and encryption and decryption. // -// clang-format off #include "privacy_crypto.h" -// clang-format on #include #include @@ -31,17 +29,17 @@ const int kRsaPkcs1OaepPaddingLength = 41; RSA* GetKey(const std::string& serialized_key) { BIO* bio = BIO_new_mem_buf(const_cast(serialized_key.data()), serialized_key.size()); - if (bio == NULL) { - LOGE("GetKey: BIO_new_mem_buf returned NULL"); - return NULL; + if (bio == nullptr) { + LOGE("BIO_new_mem_buf failed: returned null"); + return nullptr; } - RSA* key = d2i_RSAPublicKey_bio(bio, NULL); + RSA* key = d2i_RSAPublicKey_bio(bio, nullptr); - if (key == NULL) { - LOGE("GetKey: RSA key deserialization failure: %s", - ERR_error_string(ERR_get_error(), NULL)); + if (key == nullptr) { + LOGE("RSA key deserialization failure: %s", + ERR_error_string(ERR_get_error(), nullptr)); BIO_free(bio); - return NULL; + return nullptr; } BIO_free(bio); @@ -49,7 +47,7 @@ RSA* GetKey(const std::string& serialized_key) { } void FreeKey(RSA* key) { - if (key != NULL) { + if (key != nullptr) { RSA_free(key); } } @@ -57,7 +55,7 @@ void FreeKey(RSA* key) { template class boringssl_ptr { public: - explicit boringssl_ptr(T* p = NULL) : ptr_(p) {} + explicit boringssl_ptr(T* p = nullptr) : ptr_(p) {} ~boringssl_ptr() { if (ptr_) func(ptr_); } @@ -96,7 +94,8 @@ AesCbcKey::~AesCbcKey() {} bool AesCbcKey::Init(const std::string& key) { if (key.size() != AES_BLOCK_SIZE) { - LOGE("AesCbcKey::Init: unexpected key size: %d", key.size()); + LOGE("Unexpected key size: size = %zu, expected = %d", key.size(), + AES_BLOCK_SIZE); return false; } @@ -107,23 +106,23 @@ bool AesCbcKey::Init(const std::string& key) { bool AesCbcKey::Encrypt(const std::string& in, std::string* out, std::string* iv) { if (in.empty()) { - LOGE("AesCbcKey::Encrypt: no cleartext provided"); + LOGE("No cleartext provided"); return false; } - if (iv == NULL) { - LOGE("AesCbcKey::Encrypt: initialization vector destination not provided"); + if (iv == nullptr) { + LOGE("Initialization vector output parameter |iv| not provided"); return false; } if (iv->size() != AES_BLOCK_SIZE) { - LOGE("AesCbcKey::Encrypt: invalid iv size: %d", iv->size()); + LOGE("Invalid IV size: %zu", iv->size()); return false; } - if (out == NULL) { - LOGE("AesCbcKey::Encrypt: crypttext destination not provided"); + if (out == nullptr) { + LOGE("Ciphertext output parameter |out| not provided"); return false; } if (key_.empty()) { - LOGE("AesCbcKey::Encrypt: AES key not initialized"); + LOGE("AES key not initialized"); return false; } @@ -131,8 +130,8 @@ bool AesCbcKey::Encrypt(const std::string& in, std::string* out, if (EVP_EncryptInit(evp_cipher_ctx, EVP_aes_128_cbc(), reinterpret_cast(&key_[0]), reinterpret_cast(&(*iv)[0])) == 0) { - LOGE("AesCbcKey::Encrypt: AES CBC setup failure: %s", - ERR_error_string(ERR_get_error(), NULL)); + LOGE("AES CBC setup failure: %s", + ERR_error_string(ERR_get_error(), nullptr)); EVP_CIPHER_CTX_free(evp_cipher_ctx); return false; } @@ -143,8 +142,8 @@ bool AesCbcKey::Encrypt(const std::string& in, std::string* out, evp_cipher_ctx, reinterpret_cast(&(*out)[0]), &out_length, reinterpret_cast(const_cast(in.data())), in.size()) == 0) { - LOGE("AesCbcKey::Encrypt: encryption failure: %s", - ERR_error_string(ERR_get_error(), NULL)); + LOGE("AES CBC encryption failure: %s", + ERR_error_string(ERR_get_error(), nullptr)); EVP_CIPHER_CTX_free(evp_cipher_ctx); return false; } @@ -153,8 +152,8 @@ bool AesCbcKey::Encrypt(const std::string& in, std::string* out, if (EVP_EncryptFinal_ex(evp_cipher_ctx, reinterpret_cast(&(*out)[out_length]), &padding) == 0) { - LOGE("AesCbcKey::Encrypt: PKCS7 padding failure: %s", - ERR_error_string(ERR_get_error(), NULL)); + LOGE("PKCS7 padding failure: %s", + ERR_error_string(ERR_get_error(), nullptr)); EVP_CIPHER_CTX_free(evp_cipher_ctx); return false; } @@ -170,7 +169,7 @@ RsaPublicKey::~RsaPublicKey() {} bool RsaPublicKey::Init(const std::string& serialized_key) { if (serialized_key.empty()) { - LOGE("RsaPublicKey::Init: no serialized key provided"); + LOGE("No serialized key provided"); return false; } @@ -181,20 +180,20 @@ bool RsaPublicKey::Init(const std::string& serialized_key) { bool RsaPublicKey::Encrypt(const std::string& clear_message, std::string* encrypted_message) { if (clear_message.empty()) { - LOGE("RsaPublicKey::Encrypt: message to be encrypted is empty"); + LOGE("Message to be encrypted is empty"); return false; } - if (encrypted_message == NULL) { - LOGE("RsaPublicKey::Encrypt: no encrypt message buffer provided"); + if (encrypted_message == nullptr) { + LOGE("Output parameter |encrypted_message| not provided"); return false; } if (serialized_key_.empty()) { - LOGE("RsaPublicKey::Encrypt: RSA key not initialized"); + LOGE("RSA key not initialized"); return false; } RSA* key = GetKey(serialized_key_); - if (key == NULL) { + if (key == nullptr) { // Error already logged by GetKey. return false; } @@ -202,9 +201,8 @@ bool RsaPublicKey::Encrypt(const std::string& clear_message, int rsa_size = RSA_size(key); if (static_cast(clear_message.size()) > rsa_size - kRsaPkcs1OaepPaddingLength) { - LOGE("RsaPublicKey::Encrypt: message too large to be encrypted (actual %d", - " max allowed %d)", clear_message.size(), - rsa_size - kRsaPkcs1OaepPaddingLength); + LOGE("Message too large to be encrypted: message_size = %zu, max = %d", + clear_message.size(), rsa_size - kRsaPkcs1OaepPaddingLength); FreeKey(key); return false; } @@ -216,8 +214,8 @@ bool RsaPublicKey::Encrypt(const std::string& clear_message, reinterpret_cast(clear_message.data())), reinterpret_cast(&(*encrypted_message)[0]), key, RSA_PKCS1_OAEP_PADDING) != rsa_size) { - LOGE("RsaPublicKey::Encrypt: encrypt failure: %s", - ERR_error_string(ERR_get_error(), NULL)); + LOGE("RSA encryption failure: %s", + ERR_error_string(ERR_get_error(), nullptr)); FreeKey(key); return false; } @@ -237,32 +235,32 @@ static int LogBoringSSLError(const char* msg, size_t /* len */, static bool VerifyPSSSignature(EVP_PKEY* pkey, const std::string& message, const std::string& signature) { EVP_MD_CTX* evp_md_ctx = EVP_MD_CTX_new(); - EVP_PKEY_CTX* pctx = NULL; + EVP_PKEY_CTX* pctx = nullptr; - if (EVP_DigestVerifyInit(evp_md_ctx, &pctx, EVP_sha1(), NULL /* no ENGINE */, - pkey) != 1) { - LOGE("EVP_DigestVerifyInit failed in VerifyPSSSignature"); + if (EVP_DigestVerifyInit(evp_md_ctx, &pctx, EVP_sha1(), + nullptr /* no ENGINE */, pkey) != 1) { + LOGE("EVP_DigestVerifyInit failed"); goto err; } if (EVP_PKEY_CTX_set_signature_md(pctx, const_cast(EVP_sha1())) != 1) { - LOGE("EVP_PKEY_CTX_set_signature_md failed in VerifyPSSSignature"); + LOGE("EVP_PKEY_CTX_set_signature_md failed"); goto err; } if (EVP_PKEY_CTX_set_rsa_padding(pctx, RSA_PKCS1_PSS_PADDING) != 1) { - LOGE("EVP_PKEY_CTX_set_rsa_padding failed in VerifyPSSSignature"); + LOGE("EVP_PKEY_CTX_set_rsa_padding failed"); goto err; } if (EVP_PKEY_CTX_set_rsa_pss_saltlen(pctx, kPssSaltLength) != 1) { - LOGE("EVP_PKEY_CTX_set_rsa_pss_saltlen failed in VerifyPSSSignature"); + LOGE("EVP_PKEY_CTX_set_rsa_pss_saltlen failed"); goto err; } if (EVP_DigestVerifyUpdate(evp_md_ctx, message.data(), message.size()) != 1) { - LOGE("EVP_DigestVerifyUpdate failed in VerifyPSSSignature"); + LOGE("EVP_DigestVerifyUpdate failed"); goto err; } @@ -271,9 +269,7 @@ static bool VerifyPSSSignature(EVP_PKEY* pkey, const std::string& message, const_cast( reinterpret_cast(signature.data())), signature.size()) != 1) { - LOGE( - "EVP_DigestVerifyFinal failed in VerifyPSSSignature. (Probably a bad " - "signature.)"); + LOGE("EVP_DigestVerifyFinal failed (Probably a bad signature)"); goto err; } @@ -281,7 +277,7 @@ static bool VerifyPSSSignature(EVP_PKEY* pkey, const std::string& message, return true; err: - ERR_print_errors_cb(LogBoringSSLError, NULL); + ERR_print_errors_cb(LogBoringSSLError, nullptr); EVP_MD_CTX_free(evp_md_ctx); return false; } @@ -289,26 +285,26 @@ err: bool RsaPublicKey::VerifySignature(const std::string& message, const std::string& signature) { if (serialized_key_.empty()) { - LOGE("RsaPublicKey::VerifySignature: RSA key not initialized"); + LOGE("RSA key not initialized"); return false; } if (message.empty()) { - LOGE("RsaPublicKey::VerifySignature: signed message is empty"); + LOGE("Signed message is empty"); return false; } RSA* rsa_key = GetKey(serialized_key_); - if (rsa_key == NULL) { + if (rsa_key == nullptr) { // Error already logged by GetKey. return false; } EVP_PKEY* pkey = EVP_PKEY_new(); - if (pkey == NULL) { - LOGE("RsaPublicKey::VerifySignature: EVP_PKEY allocation failed"); + if (pkey == nullptr) { + LOGE("EVP_PKEY allocation failed"); FreeKey(rsa_key); return false; } if (EVP_PKEY_set1_RSA(pkey, rsa_key) != 1) { - LOGE("RsaPublicKey::VerifySignature: failed to wrap key in an EVP_PKEY"); + LOGE("Failed to wrap key in an EVP_PKEY"); FreeKey(rsa_key); EVP_PKEY_free(pkey); return false; @@ -319,7 +315,7 @@ bool RsaPublicKey::VerifySignature(const std::string& message, EVP_PKEY_free(pkey); if (!ok) { - LOGE("RsaPublicKey::VerifySignature: RSA verify failure"); + LOGE("RSA verify failure"); return false; } @@ -332,19 +328,15 @@ bool ExtractExtensionValueFromCertificate(const std::string& cert, // Load the certificate chain into a BoringSSL X509 Stack const boringssl_ptr x509_stack( sk_X509_new_null()); - if (x509_stack.get() == NULL) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Unable to allocate X509 Stack."); + if (x509_stack.get() == nullptr) { + LOGE("Unable to allocate X509 stack"); return false; } CBS pkcs7; CBS_init(&pkcs7, reinterpret_cast(cert.data()), cert.size()); if (!PKCS7_get_certificates(x509_stack.get(), &pkcs7)) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Error getting certificate chain."); + LOGE("Error getting certificate chain"); return false; } @@ -353,17 +345,15 @@ bool ExtractExtensionValueFromCertificate(const std::string& cert, // Find the desired certificate from the stack. if (sk_X509_num(certs) <= cert_index) { LOGE( - "ExtractExtensionValueFromCertificate: " - "Expected at least %zu certificates in chain, got %d", - cert_index + 1, sk_X509_num(certs)); + "Unexpected number of certificates in chain: " + "count = %zu, minimum = %zu", + sk_X509_num(certs), cert_index + 1); return false; } X509* const intermediate_cert = sk_X509_value(certs, cert_index); - if (!intermediate_cert) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Unable to get intermediate cert."); + if (intermediate_cert == nullptr) { + LOGE("Unable to get intermediate cert"); return false; } @@ -371,11 +361,8 @@ bool ExtractExtensionValueFromCertificate(const std::string& cert, const int extension_count = X509_get_ext_count(intermediate_cert); for (int i = 0; i < extension_count; ++i) { X509_EXTENSION* const extension = X509_get_ext(intermediate_cert, i); - if (!extension) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Unable to get cert extension %d", - i); + if (extension == nullptr) { + LOGE("Unable to get cert extension: cert_index = %d", i); continue; } @@ -386,36 +373,28 @@ bool ExtractExtensionValueFromCertificate(const std::string& cert, } ASN1_OCTET_STRING* const octet_str = X509_EXTENSION_get_data(extension); - if (!octet_str) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Unable to get data of extension."); + if (octet_str == nullptr) { + LOGE("Unable to get data of cert extension"); return false; } const unsigned char* data = octet_str->data; - if (!data) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Null data in extension."); + if (data == nullptr) { + LOGE("Null data in cert extension"); return false; } ASN1_INTEGER* const asn1_integer = - d2i_ASN1_INTEGER(NULL, &data, octet_str->length); - if (!asn1_integer) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Unable to decode data in extension."); + d2i_ASN1_INTEGER(nullptr, &data, octet_str->length); + if (asn1_integer == nullptr) { + LOGE("Unable to decode data in cert extension"); return false; } const long system_id_long = ASN1_INTEGER_get(asn1_integer); ASN1_INTEGER_free(asn1_integer); if (system_id_long == -1) { - LOGE( - "ExtractExtensionValueFromCertificate: " - "Unable to decode ASN integer in extension."); + LOGE("Unable to decode ASN integer in extension"); return false; } @@ -423,7 +402,7 @@ bool ExtractExtensionValueFromCertificate(const std::string& cert, return true; } - LOGE("ExtractExtensionValueFromCertificate: Extension not found."); + LOGE("Cert extension not found"); return false; } diff --git a/libwvdrmengine/cdm/core/src/privacy_crypto_dummy.cpp b/libwvdrmengine/cdm/core/src/privacy_crypto_dummy.cpp index dda72439..87412a95 100644 --- a/libwvdrmengine/cdm/core/src/privacy_crypto_dummy.cpp +++ b/libwvdrmengine/cdm/core/src/privacy_crypto_dummy.cpp @@ -7,19 +7,20 @@ // can't tolerate BoringSSL or OpenSSL as a dependency. // -#include "log.h" #include "privacy_crypto.h" #ifdef __APPLE__ -#include -#define SHA256 CC_SHA256 -#define SHA256_DIGEST_LENGTH CC_SHA256_DIGEST_LENGTH -#define MD5 CC_MD5 -#define MD5_DIGEST_LENGTH CC_MD5_DIGEST_LENGTH +# include +# define SHA256 CC_SHA256 +# define SHA256_DIGEST_LENGTH CC_SHA256_DIGEST_LENGTH +# define MD5 CC_MD5 +# define MD5_DIGEST_LENGTH CC_MD5_DIGEST_LENGTH #else -#error "No hash algorithm known for this platform." +# error "No hash algorithm known for this platform." #endif +#include "log.h" + namespace wvcdm { AesCbcKey::AesCbcKey() {} @@ -52,7 +53,7 @@ bool RsaPublicKey::VerifySignature(const std::string& message, bool ExtractExtensionValueFromCertificate(const std::string& cert, const std::string& extension_oid, size_t cert_index, uint32_t* value) { - LOGE("ExtractExtensionValueFromCertificate: Not supported in this build."); + LOGE("Not supported in this build"); return false; } diff --git a/libwvdrmengine/cdm/core/src/service_certificate.cpp b/libwvdrmengine/cdm/core/src/service_certificate.cpp index b4db2981..ff7c8ba9 100644 --- a/libwvdrmengine/cdm/core/src/service_certificate.cpp +++ b/libwvdrmengine/cdm/core/src/service_certificate.cpp @@ -142,17 +142,17 @@ CdmResponseType ServiceCertificate::Init(const std::string& certificate) { // Load root cert public key. Don't bother verifying it. SignedDrmDeviceCertificate signed_root_cert; if (!signed_root_cert.ParseFromString(root_cert_str)) { - LOGE("Failed to deserialize signed root certificate."); + LOGE("Failed to deserialize signed root certificate"); return DEVICE_CERTIFICATE_ERROR_1; } DrmDeviceCertificate root_cert; if (!root_cert.ParseFromString(signed_root_cert.drm_certificate())) { - LOGE("Failed to deserialize signed root certificate."); + LOGE("Failed to deserialize root certificate"); return DEVICE_CERTIFICATE_ERROR_1; } RsaPublicKey root_key; if (!root_key.Init(root_cert.public_key())) { - LOGE("Failed to load root certificate public key."); + LOGE("Failed to load root certificate public key"); return DEVICE_CERTIFICATE_ERROR_1; } @@ -160,22 +160,27 @@ CdmResponseType ServiceCertificate::Init(const std::string& certificate) { // First, parse it and verify its signature. SignedDrmDeviceCertificate signed_service_cert; if (!signed_service_cert.ParseFromString(certificate)) { - LOGE("Failed to parse signed service certificate."); + LOGE("Failed to parse signed service certificate"); return DEVICE_CERTIFICATE_ERROR_2; } if (!root_key.VerifySignature(signed_service_cert.drm_certificate(), signed_service_cert.signature())) { - LOGE("Service certificate signature verification failed."); + LOGE("Failed to verify service certificate signature"); return DEVICE_CERTIFICATE_ERROR_3; } DrmDeviceCertificate service_cert; if (!service_cert.ParseFromString(signed_service_cert.drm_certificate())) { - LOGE("Failed to parse service certificate."); + LOGE("Failed to parse service certificate"); return DEVICE_CERTIFICATE_ERROR_2; } if (service_cert.type() != video_widevine::DrmDeviceCertificate_CertificateType_SERVICE) { - LOGE("Not a service certificate."); + LOGE( + "DRM device certificate type is not a service certificate: " + "type = %d, expected_type = %d", + static_cast(service_cert.type()), + static_cast( + video_widevine::DrmDeviceCertificate_CertificateType_SERVICE)); return DEVICE_CERTIFICATE_ERROR_3; } @@ -183,7 +188,7 @@ CdmResponseType ServiceCertificate::Init(const std::string& certificate) { public_key_.reset(new RsaPublicKey); if (!public_key_->Init(service_cert.public_key())) { public_key_.reset(); - LOGE("Failed to load service certificate public key."); + LOGE("Failed to load service certificate public key"); return DEVICE_CERTIFICATE_ERROR_2; } @@ -198,8 +203,8 @@ CdmResponseType ServiceCertificate::Init(const std::string& certificate) { CdmResponseType ServiceCertificate::VerifySignedMessage( const std::string& message, const std::string& signature) { - if (public_key_.get() == NULL) { - LOGE("Service certificate not set."); + if (public_key_.get() == nullptr) { + LOGE("Service certificate not set"); return DEVICE_CERTIFICATE_ERROR_4; } @@ -211,8 +216,8 @@ CdmResponseType ServiceCertificate::VerifySignedMessage( CdmResponseType ServiceCertificate::EncryptRsaOaep(const std::string& plaintext, std::string* ciphertext) { - if (public_key_.get() == NULL) { - LOGE("Service certificate not set."); + if (public_key_.get() == nullptr) { + LOGE("Service certificate not set"); return DEVICE_CERTIFICATE_ERROR_4; } @@ -235,18 +240,18 @@ CdmResponseType ServiceCertificate::EncryptClientId( key.size(), reinterpret_cast(&key[0])); if (status != NO_ERROR) { - LOGE("ServiceCertificate::EncryptClientId: GetRandom error: %d", status); - return status == RANDOM_GENERATION_ERROR ? CLIENT_ID_GENERATE_RANDOM_ERROR - : status; + LOGE("GetRandom failed for key: status = %d", static_cast(status)); + return (status == RANDOM_GENERATION_ERROR) ? CLIENT_ID_GENERATE_RANDOM_ERROR + : status; } status = crypto_session->GetRandom(iv.size(), reinterpret_cast(&iv[0])); if (status != NO_ERROR) { - LOGE("ServiceCertificate::EncryptClientId: GetRandom error: %d", status); - return status == RANDOM_GENERATION_ERROR ? CLIENT_ID_GENERATE_RANDOM_ERROR - : status; + LOGE("GetRandom failed for IV: status = %d", static_cast(status)); + return (status == RANDOM_GENERATION_ERROR) ? CLIENT_ID_GENERATE_RANDOM_ERROR + : status; } std::string id, enc_id, enc_key; clear_client_id->SerializeToString(&id); @@ -265,8 +270,8 @@ CdmResponseType ServiceCertificate::EncryptClientId( } bool ServiceCertificate::GetRequest(CdmKeyMessage* request) { - if (!request) { - LOGE("ServiceCertificate::PrepareRequest: no request parameter provided"); + if (request == nullptr) { + LOGE("Output parameter |request| not provided"); return false; } SignedMessage message; @@ -278,34 +283,35 @@ bool ServiceCertificate::GetRequest(CdmKeyMessage* request) { CdmResponseType ServiceCertificate::ParseResponse(const std::string& response, std::string* certificate) { if (response.empty()) { - LOGE("ServiceCertificate::ParseResponse: empty response"); + LOGE("Response is empty"); return EMPTY_RESPONSE_ERROR_1; } - if (!certificate) { - LOGE("ServiceCertificate::ParseResponse: null return parameter"); + if (certificate == nullptr) { + LOGE("Output parameter |certificate| not provided"); return INVALID_PARAMETERS_ENG_24; } SignedMessage signed_response; if (!signed_response.ParseFromString(response)) { - LOGE("ServiceCertificate::ParseResponse: cannot parse response"); + LOGE("Failed to parse signed response"); return PARSE_RESPONSE_ERROR_1; } if (signed_response.type() == SignedMessage::ERROR_RESPONSE) { LicenseError license_error; if (!license_error.ParseFromString(signed_response.msg())) { - LOGE("ServiceCertificate::ParseResponse: cannot parse license error"); + LOGE("Failed to parse license error"); return PARSE_RESPONSE_ERROR_2; } - LOGE("ServiceCertificate::ParseResponse: server returned error = %d", - license_error.error_code()); + LOGE("Server response contains error: error_code = %d", + static_cast(license_error.error_code())); return PARSE_RESPONSE_ERROR_3; } if (signed_response.type() != SignedMessage::SERVICE_CERTIFICATE) { - LOGE("ServiceCertificate::ParseResponse: response (%d) is wrong type", - signed_response.type()); + LOGE("Unexpected response type: type = %d, expected_type = %d", + static_cast(signed_response.type()), + static_cast(SignedMessage::SERVICE_CERTIFICATE)); return PARSE_RESPONSE_ERROR_4; } diff --git a/libwvdrmengine/cdm/core/src/usage_table_header.cpp b/libwvdrmengine/cdm/core/src/usage_table_header.cpp index 9233d422..5ab7de2e 100644 --- a/libwvdrmengine/cdm/core/src/usage_table_header.cpp +++ b/libwvdrmengine/cdm/core/src/usage_table_header.cpp @@ -35,9 +35,10 @@ UsageTableHeader::UsageTableHeader() bool UsageTableHeader::Init(CdmSecurityLevel security_level, CryptoSession* crypto_session) { - LOGI("UsageTableHeader::Init: security level: %d", security_level); - if (crypto_session == NULL) { - LOGE("UsageTableHeader::Init: no crypto session provided"); + LOGI("Initializing usage table header: security_level = %d", + static_cast(security_level)); + if (crypto_session == nullptr) { + LOGE("No crypto session provided"); return false; } @@ -46,8 +47,8 @@ bool UsageTableHeader::Init(CdmSecurityLevel security_level, case kSecurityLevelL3: break; default: - LOGE("UsageTableHeader::Init: invalid security level provided: %d", - security_level); + LOGE("Invalid security level provided: security_level = %d", + static_cast(security_level)); return false; } @@ -56,18 +57,17 @@ bool UsageTableHeader::Init(CdmSecurityLevel security_level, security_level_ == kSecurityLevelL3 ? kLevel3 : kLevelDefault; if (!file_handle_->Init(security_level)) { - LOGE("UsageTableHeader::Init: device files initialization failed"); + LOGE("Failed to initialize device files"); return false; } CdmResponseType status = USAGE_INFO_NOT_FOUND; metrics::CryptoMetrics* metrics = crypto_session->GetCryptoMetrics(); - if (metrics == NULL) metrics = &alternate_crypto_metrics_; + if (metrics == nullptr) metrics = &alternate_crypto_metrics_; if (file_handle_->RetrieveUsageTableInfo(&usage_table_header_, &usage_entry_info_)) { - LOGI("UsageTableHeader::Init: number of usage entries: %d", - usage_entry_info_.size()); + LOGI("Number of usage entries: %zu", usage_entry_info_.size()); status = crypto_session->LoadUsageTableHeader(usage_table_header_); // If the usage table header has been successfully loaded, and is at @@ -85,7 +85,7 @@ bool UsageTableHeader::Init(CdmSecurityLevel security_level, // method or a test object whose scope is the lifetime of this class std::unique_ptr scoped_crypto_session; CryptoSession* local_crypto_session = test_crypto_session_.get(); - if (local_crypto_session == NULL) { + if (local_crypto_session == nullptr) { scoped_crypto_session.reset( (CryptoSession::MakeCryptoSession(metrics))); local_crypto_session = scoped_crypto_session.get(); @@ -103,18 +103,17 @@ bool UsageTableHeader::Init(CdmSecurityLevel security_level, } if (result != NO_ERROR) { LOGE( - "UsageTableHeader::Init: Unable to create/delete new entry. " - "Clear usage entries, security level: %d, usage entries: %d", - security_level, usage_entry_info_.size()); + "Unable to create/delete new entry, clearing usage entries: " + "security_level = %d, usage_entry_count = %zu", + static_cast(security_level), usage_entry_info_.size()); status = result; } } } if (status != NO_ERROR) { - LOGE( - "UsageTableHeader::Init: load usage table failed, security level: %d", - security_level); + LOGE("Failed to load usage table: security_level = %d", + static_cast(security_level)); file_handle_->DeleteAllLicenses(); file_handle_->DeleteAllUsageInfo(); file_handle_->DeleteUsageTableInfo(); @@ -141,10 +140,10 @@ CdmResponseType UsageTableHeader::AddEntry( CryptoSession* crypto_session, bool persistent_license, const CdmKeySetId& key_set_id, const std::string& usage_info_file_name, uint32_t* usage_entry_number) { - LOGI("UsageTableHeader::AddEntry: Lock"); + LOGI("Adding usage entry"); metrics::CryptoMetrics* metrics = crypto_session->GetCryptoMetrics(); - if (metrics == NULL) metrics = &alternate_crypto_metrics_; + if (metrics == nullptr) metrics = &alternate_crypto_metrics_; CdmResponseType status = crypto_session->CreateUsageEntry(usage_entry_number); @@ -162,16 +161,21 @@ CdmResponseType UsageTableHeader::AddEntry( if (status != NO_ERROR) return status; + LOGI("Locking to add entry"); std::unique_lock auto_lock(usage_table_header_lock_); if (*usage_entry_number < usage_entry_info_.size()) { - LOGE("UsageTableHeader::AddEntry: new entry %d smaller than table size: %d", - *usage_entry_number, usage_entry_info_.size()); + LOGE( + "New entry number is smaller than table size: " + "entry_info_number = %u, table_size = %zu", + *usage_entry_number, usage_entry_info_.size()); return USAGE_INVALID_NEW_ENTRY; } if (*usage_entry_number > usage_entry_info_.size()) { - LOGW("UsageTableHeader::AddEntry: new entry %d larger than table size: %d", - *usage_entry_number, usage_entry_info_.size()); + LOGW( + "New entry number is larger than table size, resizing: " + "entry_info_number = %u, table_size = %zu", + *usage_entry_number, usage_entry_info_.size()); size_t number_of_entries = usage_entry_info_.size(); usage_entry_info_.resize(*usage_entry_number + 1); for (size_t i = number_of_entries; i < usage_entry_info_.size() - 1; ++i) { @@ -190,7 +194,7 @@ CdmResponseType UsageTableHeader::AddEntry( usage_entry_info_[*usage_entry_number].usage_info_file_name = usage_info_file_name; - LOGI("UsageTableHeader::AddEntry: usage entry #: %d", *usage_entry_number); + LOGI("New usage entry: usage_entry_number = %u", *usage_entry_number); file_handle_->StoreUsageTableInfo(usage_table_header_, usage_entry_info_); return NO_ERROR; } @@ -199,20 +203,19 @@ CdmResponseType UsageTableHeader::LoadEntry(CryptoSession* crypto_session, const CdmUsageEntry& usage_entry, uint32_t usage_entry_number) { { - LOGI("UsageTableHeader::LoadEntry: Lock: usage entry #: %d", - usage_entry_number); + LOGI("Locking to load entry: 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( - "UsageTableHeader::LoadEntry: usage entry number %d larger than " - "table size: %d", + "Requested usage entry number is larger than table size: " + "usage_entry_number = %u, table_size = %zu", usage_entry_number, usage_entry_info_.size()); return USAGE_INVALID_LOAD_ENTRY; } } metrics::CryptoMetrics* metrics = crypto_session->GetCryptoMetrics(); - if (metrics == NULL) metrics = &alternate_crypto_metrics_; + if (metrics == nullptr) metrics = &alternate_crypto_metrics_; CdmResponseType status = crypto_session->LoadUsageEntry(usage_entry_number, usage_entry); @@ -236,7 +239,7 @@ CdmResponseType UsageTableHeader::LoadEntry(CryptoSession* crypto_session, CdmResponseType UsageTableHeader::UpdateEntry(CryptoSession* crypto_session, CdmUsageEntry* usage_entry) { - LOGI("UsageTableHeader::UpdateEntry: Lock"); + LOGI("Locking to update entry"); std::unique_lock auto_lock(usage_table_header_lock_); CdmResponseType status = crypto_session->UpdateUsageEntry(&usage_table_header_, usage_entry); @@ -250,13 +253,12 @@ CdmResponseType UsageTableHeader::UpdateEntry(CryptoSession* crypto_session, CdmResponseType UsageTableHeader::DeleteEntry(uint32_t usage_entry_number, DeviceFiles* handle, metrics::CryptoMetrics* metrics) { - LOGI("UsageTableHeader::DeleteEntry: Lock: usage entry #: %d", - usage_entry_number); + LOGI("Locking to delete entry: 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( - "UsageTableHeader::DeleteEntry: usage entry number %d larger than " - "usage entry size %d", + "Usage entry number is larger than table size: " + "usage_entry_number = %u, table_size = %zu", usage_entry_number, usage_entry_info_.size()); return USAGE_INVALID_PARAMETERS_1; } @@ -311,14 +313,16 @@ CdmResponseType UsageTableHeader::MoveEntry( uint32_t from_usage_entry_number, const CdmUsageEntry& from_usage_entry, uint32_t to_usage_entry_number, DeviceFiles* handle, metrics::CryptoMetrics* metrics) { - LOGI("UsageTableHeader::MoveEntry: usage entry #: %d -> %d", - from_usage_entry_number, to_usage_entry_number); + LOGI( + "Moving usage entry: " + "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 std::unique_ptr scoped_crypto_session; CryptoSession* crypto_session = test_crypto_session_.get(); - if (crypto_session == NULL) { + if (crypto_session == nullptr) { scoped_crypto_session.reset((CryptoSession::MakeCryptoSession(metrics))); crypto_session = scoped_crypto_session.get(); } @@ -329,7 +333,7 @@ CdmResponseType UsageTableHeader::MoveEntry( crypto_session->LoadUsageEntry(from_usage_entry_number, from_usage_entry); if (status != NO_ERROR) { - LOGE("UsageTableHeader::MoveEntry: Failed to load usage entry: %d", + LOGE("Failed to load usage entry: usage_entry_number = %u", from_usage_entry_number); return status; } @@ -337,8 +341,10 @@ CdmResponseType UsageTableHeader::MoveEntry( status = crypto_session->MoveUsageEntry(to_usage_entry_number); if (status != NO_ERROR) { - LOGE("UsageTableHeader::MoveEntry: Failed to move usage entry: %d->%d", - from_usage_entry_number, to_usage_entry_number); + LOGE( + "Failed to move usage entry: " + "from_usage_entry_number = %u, to_usage_entry_number = %u", + from_usage_entry_number, to_usage_entry_number); return status; } @@ -349,7 +355,7 @@ CdmResponseType UsageTableHeader::MoveEntry( status = crypto_session->UpdateUsageEntry(&usage_table_header_, &usage_entry); if (status != NO_ERROR) { - LOGE("UsageTableHeader::MoveEntry: Failed to update usage entry: %d", + LOGE("Failed to update usage entry: usage_entry_number = %u", to_usage_entry_number); return status; } @@ -364,8 +370,11 @@ CdmResponseType UsageTableHeader::MoveEntry( CdmResponseType UsageTableHeader::GetEntry(uint32_t usage_entry_number, DeviceFiles* handle, CdmUsageEntry* usage_entry) { - LOGI("UsageTableHeader::GetEntry: usage entry #: %d, storage type: %d", - usage_entry_number, usage_entry_info_[usage_entry_number].storage_type); + 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)); uint32_t entry_number; switch (usage_entry_info_[usage_entry_number].storage_type) { case kStorageLicense: { @@ -381,8 +390,8 @@ CdmResponseType UsageTableHeader::GetEntry(uint32_t usage_entry_number, &key_renewal_response, &release_server_url, &playback_start_time, &last_playback_time, &grace_period_end_time, &app_parameters, usage_entry, &entry_number, &sub_error_code)) { - LOGE("UsageTableHeader::GetEntry: Failed to retrieve license, %d", - sub_error_code); + LOGE("Failed to retrieve license: status = %d", + static_cast(sub_error_code)); return USAGE_GET_ENTRY_RETRIEVE_LICENSE_FAILED; } break; @@ -397,8 +406,7 @@ CdmResponseType UsageTableHeader::GetEntry(uint32_t usage_entry_number, usage_entry_info_[usage_entry_number].key_set_id, &provider_session_token, &license_request, &license_response, usage_entry, &entry_number)) { - LOGE( - "UsageTableHeader::GetEntry: Failed to retrieve usage information"); + LOGE("Failed to retrieve usage information"); return USAGE_GET_ENTRY_RETRIEVE_USAGE_INFO_FAILED; } break; @@ -406,15 +414,17 @@ CdmResponseType UsageTableHeader::GetEntry(uint32_t usage_entry_number, case kStorageTypeUnknown: default: LOGE( - "UsageTableHeader::GetEntry: Attempting to retrieve usage " - "information from unknown storage type: %d", - usage_entry_info_[usage_entry_number].storage_type); + "Cannot retrieve usage information with unknown storage type: " + "storage_type = %d", + static_cast(usage_entry_info_[usage_entry_number].storage_type)); return USAGE_GET_ENTRY_RETRIEVE_INVALID_STORAGE_TYPE; } if (usage_entry_number != entry_number) { - LOGE("UsageTableHeader::GetEntry: entry number mismatch: (%d, %d)", - usage_entry_number, entry_number); + LOGE( + "Usage entry number mismatch: expected_usage_entry_number = %u, " + "retrieved_usage_entry_number = %u", + usage_entry_number, entry_number); return USAGE_ENTRY_NUMBER_MISMATCH; } @@ -424,8 +434,11 @@ CdmResponseType UsageTableHeader::GetEntry(uint32_t usage_entry_number, CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, DeviceFiles* handle, const CdmUsageEntry& usage_entry) { - LOGI("UsageTableHeader::StoreEntry: usage entry #: %d, storage type: %d", - usage_entry_number, usage_entry_info_[usage_entry_number].storage_type); + 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)); uint32_t entry_number; switch (usage_entry_info_[usage_entry_number].storage_type) { case kStorageLicense: { @@ -442,8 +455,8 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, &key_renewal_response, &release_server_url, &playback_start_time, &last_playback_time, &grace_period_end_time, &app_parameters, &entry, &entry_number, &sub_error_code)) { - LOGE("UsageTableHeader::StoreEntry: Failed to retrieve license, %d", - sub_error_code); + LOGE("Failed to retrieve license: status = %d", + static_cast(sub_error_code)); return USAGE_STORE_ENTRY_RETRIEVE_LICENSE_FAILED; } if (!handle->StoreLicense( @@ -452,8 +465,8 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, key_renewal_response, release_server_url, playback_start_time, last_playback_time, grace_period_end_time, app_parameters, usage_entry, usage_entry_number, &sub_error_code)) { - LOGE("UsageTableHeader::StoreEntry: Failed to store license, %d", - sub_error_code); + LOGE("Failed to store license: status = %d", + static_cast(sub_error_code)); return USAGE_STORE_LICENSE_FAILED; } break; @@ -467,9 +480,7 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, usage_entry_info_[usage_entry_number].key_set_id, &provider_session_token, &key_request, &key_response, &entry, &entry_number)) { - LOGE( - "UsageTableHeader::StoreEntry: Failed to retrieve usage " - "information"); + LOGE("Failed to retrieve usage information"); return USAGE_STORE_ENTRY_RETRIEVE_USAGE_INFO_FAILED; } handle->DeleteUsageInfo( @@ -480,7 +491,7 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, usage_entry_info_[usage_entry_number].usage_info_file_name, usage_entry_info_[usage_entry_number].key_set_id, usage_entry, usage_entry_number)) { - LOGE("UsageTableHeader::StoreEntry: Failed to store usage information"); + LOGE("Failed to store usage information"); return USAGE_STORE_USAGE_INFO_FAILED; } break; @@ -488,9 +499,9 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, case kStorageTypeUnknown: default: LOGE( - "UsageTableHeader::GetUsageEntry: Attempting to retrieve usage " - "information from unknown storage type: %d", - usage_entry_info_[usage_entry_number].storage_type); + "Cannot retrieve usage information with unknown storage type: " + "storage_type = %d", + static_cast(usage_entry_info_[usage_entry_number].storage_type)); return USAGE_STORE_ENTRY_RETRIEVE_INVALID_STORAGE_TYPE; } return NO_ERROR; @@ -499,10 +510,10 @@ CdmResponseType UsageTableHeader::StoreEntry(uint32_t usage_entry_number, CdmResponseType UsageTableHeader::Shrink( metrics::CryptoMetrics* metrics, uint32_t number_of_usage_entries_to_delete) { - LOGI("UsageTableHeader::Shrink: %d (of %d)", - number_of_usage_entries_to_delete, usage_entry_info_.size()); + LOGI("Shrinking usage table: table_size = %zu, number_to_delete = %u", + usage_entry_info_.size(), number_of_usage_entries_to_delete); if (usage_entry_info_.empty()) { - LOGE("UsageTableHeader::Shrink: usage entry info table unexpectedly empty"); + LOGE("Usage entry info table unexpectedly empty"); return NO_USAGE_ENTRIES; } @@ -523,7 +534,7 @@ CdmResponseType UsageTableHeader::Shrink( // object whose scope is the lifetime of this class std::unique_ptr scoped_crypto_session; CryptoSession* crypto_session = test_crypto_session_.get(); - if (crypto_session == NULL) { + if (crypto_session == nullptr) { scoped_crypto_session.reset(CryptoSession::MakeCryptoSession(metrics)); crypto_session = scoped_crypto_session.get(); } @@ -557,9 +568,7 @@ bool UsageTableHeader::UpgradeLicensesFromUsageTable( // usage entry along with the license to persistent memory std::vector key_set_ids; if (!handle->ListLicenses(&key_set_ids)) { - LOGW( - "UpgradeUsageTableHeader::UpgradeLicensesFromUsageTable: unable to " - "retrieve list of licenses"); + LOGE("Unable to retrieve list of licenses"); return false; } @@ -578,19 +587,15 @@ bool UsageTableHeader::UpgradeLicensesFromUsageTable( &release_server_url, &playback_start_time, &last_playback_time, &grace_period_end_time, &app_parameters, &usage_entry, &usage_entry_number, &sub_error_code)) { - LOGW( - "UsageTableHeader::UpgradeLicensesFromUsageTable: Failed to " - "retrieve license, %d", - sub_error_code); + LOGW("Failed to retrieve license: key_set_index = %zu, status = %d", i, + static_cast(sub_error_code)); continue; } std::string provider_session_token; if (!CdmLicense::ExtractProviderSessionToken(key_response, &provider_session_token)) { - LOGW( - "UsageTableHeader::UpgradeLicensesFromUsageTable: Failed to " - "retrieve provider session token"); + LOGW("Failed to extract provider session token: key_set_index = %zu", i); continue; } @@ -632,10 +637,8 @@ bool UsageTableHeader::UpgradeLicensesFromUsageTable( key_renewal_request, key_renewal_response, release_server_url, playback_start_time, last_playback_time, grace_period_end_time, app_parameters, usage_entry, usage_entry_number, &sub_error_code)) { - LOGE( - "UsageTableHeader::UpgradeLicensesFromUsageTable: Failed to store " - "license, %d", - sub_error_code); + LOGW("Failed to store license: key_set_index = %zu, status = %d", i, + static_cast(sub_error_code)); continue; } } @@ -656,27 +659,21 @@ bool UsageTableHeader::UpgradeUsageInfoFromUsageTable( // entry. std::vector usage_info_file_names; if (!handle->ListUsageInfoFiles(&usage_info_file_names)) { - LOGW( - "UpgradeUsageTableHeader::UpgradeUsageInfoFromUsageTable: Unable to " - "retrieve list of usage info file names"); + LOGE("Unable to retrieve list of usage info file names"); return false; } for (size_t i = 0; i < usage_info_file_names.size(); ++i) { std::vector usage_data; if (!handle->RetrieveUsageInfo(usage_info_file_names[i], &usage_data)) { - LOGW( - "UsageTableHeader::UpgradeUsageInfoFromUsageTable: Failed to " - "retrieve usage records from %s", - usage_info_file_names[i].c_str()); + LOGW("Failed to retrieve usage records: usage_info_file_name = %s", + usage_info_file_names[i].c_str()); continue; } for (size_t j = 0; j < usage_data.size(); ++j) { if (usage_data[j].provider_session_token.empty()) { - LOGW( - "UsageTableHeader::UpgradeUsageInfoFromUsageTable: Provider " - "session id empty"); + LOGW("Provider session ID is empty"); continue; } @@ -717,10 +714,8 @@ bool UsageTableHeader::UpgradeUsageInfoFromUsageTable( } if (!handle->StoreUsageInfo(usage_info_file_names[i], usage_data)) { - LOGE( - "UsageTableHeader::StoreUsageInfo: Failed to store usage records to " - "%s", - usage_info_file_names[i].c_str()); + LOGE("Failed to store upgraded usage records: usage_info_file_name = %s", + usage_info_file_names[i].c_str()); continue; } } @@ -730,7 +725,7 @@ bool UsageTableHeader::UpgradeUsageInfoFromUsageTable( int64_t UsageTableHeader::GetRandomInRange(size_t upper_bound_exclusive) { if (upper_bound_exclusive == 0) { - LOGE("upper_bound_exclusive must be > 0."); + LOGE("|upper_bound_exclusive| must be > 0"); return -1; } return (int)((double)rand() / ((double)RAND_MAX + 1) * upper_bound_exclusive); @@ -740,8 +735,8 @@ int64_t UsageTableHeader::GetRandomInRangeWithExclusion( size_t upper_bound_exclusive, size_t exclude) { if ((upper_bound_exclusive <= 1) || (exclude >= upper_bound_exclusive)) { LOGE( - "upper_bound_exclusive must be > 1 and exclude must be < " - "upper_bound_exclusive."); + "|upper_bound_exclusive| must be > 1 and |exclude| must be < " + "|upper_bound_exclusive|"); return -1; } uint32_t random = GetRandomInRange(upper_bound_exclusive - 1); @@ -760,12 +755,11 @@ bool UsageTableHeader::CreateDummyOldUsageEntry(CryptoSession* crypto_session) { // Test only method. void UsageTableHeader::DeleteEntryForTest(uint32_t usage_entry_number) { - LOGV("UsageTableHeader::DeleteEntryForTest: usage_entry_number: %d", - usage_entry_number); + LOGV("Deleting entry for test: usage_entry_number = %u", usage_entry_number); if (usage_entry_number >= usage_entry_info_.size()) { LOGE( - "UsageTableHeader::DeleteEntryForTest: usage entry number %d larger " - "than usage entry size %d", + "Requested usage entry number is larger than table size: " + "usage_entry_number = %u, table_size = %zu", usage_entry_number, usage_entry_info_.size()); return; }