From be448ed24a74656db85eddfe0a2ffb554425fb58 Mon Sep 17 00:00:00 2001 From: Aaron Vaage Date: Sat, 28 Jan 2017 11:55:59 -0800 Subject: [PATCH] Collect Errors and Warnings In OEMCrypto Initialize As a large number of provisioning errors can come from failures initializing OEMCrypto we need to collect these messages. Errors and warnings were only printed to the log. This change takes those messages and puts them into the oemcrypto intialization mode metric. "Mode" was chosen as most messages were about how oemcrypto was initialized (e.g. into L3 because no L1 library was found). Test: Ran all GTS Media Tests Bug: 34782934 Change-Id: I1fcdd74c99011d53bdffe9609d2f4c46c222e2f6 --- .../core/src/oemcrypto_adapter_dynamic.cpp | 96 ++++++++++++++++++- .../cdm/metrics/include/metrics_front_end.h | 6 +- .../cdm/metrics/include/metrics_group.h | 23 +++++ .../cdm/metrics/src/metrics_group.cpp | 11 ++- 4 files changed, 131 insertions(+), 5 deletions(-) diff --git a/libwvdrmengine/cdm/core/src/oemcrypto_adapter_dynamic.cpp b/libwvdrmengine/cdm/core/src/oemcrypto_adapter_dynamic.cpp index abaa2cbc..290414e5 100644 --- a/libwvdrmengine/cdm/core/src/oemcrypto_adapter_dynamic.cpp +++ b/libwvdrmengine/cdm/core/src/oemcrypto_adapter_dynamic.cpp @@ -29,6 +29,8 @@ #include "level3.h" #include "lock.h" #include "log.h" +#include "metrics_front_end.h" +#include "metrics_group.h" #include "properties.h" #include "wv_cdm_constants.h" @@ -400,6 +402,14 @@ class Adapter { } OEMCryptoResult Initialize() { + + /* + * To avoid changing the function signature and function contract - declare + * a one-off metrics group to collect detailed information about how + * oemcrypto was intialized. + */ + wvcdm::metrics::MetricsGroup metrics; + LoadLevel3(); std::string base_path; wvcdm::Properties::GetDeviceFilesBasePath(wvcdm::kSecurityLevelL3, @@ -407,24 +417,44 @@ class Adapter { bool is_in_app = Level3_IsInApp(base_path.c_str()); OEMCryptoResult result = Level3_Initialize(clear_cache_function); if (is_in_app) { + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_IN_APP); return result; } if (force_level3()) { LOGW("Test code. User requested falling back to L3"); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_FORCING_L3); return result; } std::string library_name; if (!wvcdm::Properties::GetOEMCryptoPath(&library_name)) { LOGW("L1 library not specified. Falling back to L3"); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_NO_L1_LIBRARY_PATH); return result; } level1_library_ = dlopen(library_name.c_str(), RTLD_NOW); if (level1_library_ == NULL) { LOGW("Could not load %s. Falling back to L3. %s", library_name.c_str(), dlerror()); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_L1_OPEN_FAILED); return result; } - if (LoadLevel1()) { + if (LoadLevel1(metrics)) { LOGD("OEMCrypto_Initialize Level 1 success. I will use level 1."); } else { level1_ = FunctionPointers(); // revert to all null pointers. @@ -435,7 +465,7 @@ class Adapter { return result; } - bool LoadLevel1() { + bool LoadLevel1(wvcdm::metrics::MetricsGroup& metrics) { level1_valid_ = true; LOOKUP(Initialize, OEMCrypto_Initialize); LOOKUP(Terminate, OEMCrypto_Terminate); @@ -462,18 +492,39 @@ class Adapter { LOOKUP(Generic_Sign, OEMCrypto_Generic_Sign); LOOKUP(Generic_Verify, OEMCrypto_Generic_Verify); if (!level1_valid_) { + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_INVALID_L1); return false; } OEMCryptoResult st = level1_.Initialize(); if (st != OEMCrypto_SUCCESS) { LOGW("Could not initialize L1. Falling Back to L3."); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_COULD_NOT_INITIALIZE_L1); return false; } level1_.version = level1_.APIVersion(); const uint32_t kMinimumVersion = 8; + M_RECORD( + &metrics, + oemcrypto_l1_api_version_, + NO_TIME, + level1_.version, + kMinimumVersion); if (level1_.version < kMinimumVersion) { LOGW("liboemcrypto.so is version %d, not %d. Falling Back to L3.", level1_.version, kMinimumVersion); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_WRONG_L1_VERSION); level1_.Terminate(); return false; } @@ -546,6 +597,11 @@ class Adapter { } // If we have a valid keybox, initialization is done. We're good. if (OEMCrypto_SUCCESS == level1_.IsKeyboxValid()) { + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L1_WITH_KEYBOX); return true; } // If we use provisioning 3.0, initialization is done. We may not @@ -553,6 +609,11 @@ class Adapter { // will have to be caught in the future when provisioning fails. if (level1_.version > 11 && (level1_.GetProvisioningMethod() == OEMCrypto_OEMCertificate)) { + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L1_WITH_PROVISIONING_3_0); return true; } uint8_t buffer[1]; @@ -568,6 +629,17 @@ class Adapter { // because we still want to test OEMCrypto in that configuration. LOGE("OEMCrypto uses cert as identification, but cdm does not!"); LOGE("This will not work on a production device."); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L1_CERTIFICATE_MIX); + } else { + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L1_WITH_CERTIFICATE); } return true; } @@ -576,6 +648,11 @@ class Adapter { if (!wvcdm::Properties::GetFactoryKeyboxPath(&filename)) { LOGW("Bad Level 1 Keybox. Falling Back to L3."); level1_.Terminate(); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_BAD_KEYBOX); return false; } ssize_t size = file_system.FileSize(filename); @@ -583,6 +660,11 @@ class Adapter { if (size <= 0 || !file) { LOGW("Could not open %s. Falling Back to L3.", filename.c_str()); level1_.Terminate(); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_COULD_NOT_OPEN_FACTORY_KEYBOX); return false; } uint8_t keybox[size]; @@ -592,9 +674,19 @@ class Adapter { LOGE("Could NOT install keybox from %s. Falling Back to L3.", filename.c_str()); level1_.Terminate(); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L3_COULD_NOT_INSTALL_KEYBOX); return false; } LOGI("Installed keybox from %s", filename.c_str()); + M_RECORD( + &metrics, + oemcrypto_initialization_mode_, + NO_TIME, + wvcdm::metrics::OEMCrypto_INITIALIZED_USING_L1_INSTALLED_KEYBOX); return true; } diff --git a/libwvdrmengine/cdm/metrics/include/metrics_front_end.h b/libwvdrmengine/cdm/metrics/include/metrics_front_end.h index 20e8737a..12838a82 100644 --- a/libwvdrmengine/cdm/metrics/include/metrics_front_end.h +++ b/libwvdrmengine/cdm/metrics/include/metrics_front_end.h @@ -38,9 +38,11 @@ class MetricsFrontEnd { #define MFE wvcdm::metrics::MetricsFrontEnd::Instance() -#define M_RECORD(GROUP, METRIC, ...) \ +#define NO_TIME 0 + +#define M_RECORD(GROUP, METRIC, TIME, ...) \ if ( GROUP ) { \ - ( GROUP ) -> METRIC . Record( __VA_ARGS__ ); \ + ( GROUP ) -> METRIC . Record( TIME, ##__VA_ARGS__ ); \ } #define M_TIME(CALL, GROUP, METRIC, ...) \ diff --git a/libwvdrmengine/cdm/metrics/include/metrics_group.h b/libwvdrmengine/cdm/metrics/include/metrics_group.h index cb3e40b0..6b54a32e 100644 --- a/libwvdrmengine/cdm/metrics/include/metrics_group.h +++ b/libwvdrmengine/cdm/metrics/include/metrics_group.h @@ -14,6 +14,25 @@ namespace wvcdm { namespace metrics { +typedef enum OEMCryptoInitializationMode { + OEMCrypto_INITIALIZED_USING_IN_APP = 0, + OEMCrypto_INITIALIZED_FORCING_L3 = 1, + OEMCrypto_INITIALIZED_USING_L3_NO_L1_LIBRARY_PATH = 2, + OEMCrypto_INITIALIZED_USING_L3_L1_OPEN_FAILED = 3, + OEMCrypto_INITIALIZED_USING_L3_L1_LOAD_FAILED = 4, + OEMCrypto_INITIALIZED_USING_L3_COULD_NOT_INITIALIZE_L1 = 5, + OEMCrypto_INITIALIZED_USING_L3_WRONG_L1_VERSION = 6, + OEMCrypto_INITIALIZED_USING_L1_WITH_KEYBOX = 7, + OEMCrypto_INITIALIZED_USING_L1_WITH_CERTIFICATE = 8, + OEMCrypto_INITIALIZED_USING_L1_CERTIFICATE_MIX = 9, + OEMCrypto_INITIALIZED_USING_L3_BAD_KEYBOX = 10, + OEMCrypto_INITIALIZED_USING_L3_COULD_NOT_OPEN_FACTORY_KEYBOX = 11, + OEMCrypto_INITIALIZED_USING_L3_COULD_NOT_INSTALL_KEYBOX = 12, + OEMCrypto_INITIALIZED_USING_L1_INSTALLED_KEYBOX = 13, + OEMCrypto_INITIALIZED_USING_L3_INVALID_L1 = 14, + OEMCrypto_INITIALIZED_USING_L1_WITH_PROVISIONING_3_0 = 15 +} OEMCryptoInitializationMode; + /* * The metrics group is the group of all metrics that be be recorded. They * are kept together to allow calls to be correlated to one another. @@ -138,6 +157,10 @@ class MetricsGroup { EventMetric oemcrypto_update_usage_table_; EventMetric oemcrypto_wrap_keybox_; + /* Internal OEMCrypto Metrics */ + EventMetric oemcrypto_initialization_mode_; + EventMetric oemcrypto_l1_api_version_; + MetricsGroup(); ~MetricsGroup(); diff --git a/libwvdrmengine/cdm/metrics/src/metrics_group.cpp b/libwvdrmengine/cdm/metrics/src/metrics_group.cpp index 969688db..b1a3fd4a 100644 --- a/libwvdrmengine/cdm/metrics/src/metrics_group.cpp +++ b/libwvdrmengine/cdm/metrics/src/metrics_group.cpp @@ -383,7 +383,14 @@ MetricsGroup::MetricsGroup() : "error"), oemcrypto_wrap_keybox_( "/drm/widevine/oemcrypto/wrap_keybox/time", - "error") { } + "error"), + oemcrypto_initialization_mode_( + "/drm/widevine/oemcrypto/initialization_mode", + "message"), + oemcrypto_l1_api_version_( + "/drm/widevine/oemcrypto/l1_api_version", + "version", + "min_version") { } MetricsGroup::~MetricsGroup() { MetricNotification* subscriber = MFE.CreateSubscriber(); @@ -506,6 +513,8 @@ void MetricsGroup::Publish(MetricNotification* subscriber) { oemcrypto_supports_usage_table_.Publish(subscriber); oemcrypto_update_usage_table_.Publish(subscriber); oemcrypto_wrap_keybox_.Publish(subscriber); + oemcrypto_initialization_mode_.Publish(subscriber); + oemcrypto_l1_api_version_.Publish(subscriber); } } // metrics } // wvcdm