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

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;
   }
 

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, ...) \

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<OEMCryptoResult> oemcrypto_update_usage_table_;
   EventMetric<OEMCryptoResult> oemcrypto_wrap_keybox_;
 
+  /* Internal OEMCrypto Metrics */
+  EventMetric<OEMCryptoInitializationMode> oemcrypto_initialization_mode_;
+  EventMetric<uint32_t, uint32_t> oemcrypto_l1_api_version_;
+
   MetricsGroup();
   ~MetricsGroup();
 

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