Log more license information

This CL logs some extra policy information from a license.

Bug: 305794515
Bug: 311529487

Merged from https://widevine-internal-review.googlesource.com/187887

Change-Id: I707afbb01b5467d2551c68a9152ca078815544eb

libwvdrmengine/cdm/core/test/message_dumper.cpp

@@ -48,6 +48,63 @@ void DumpHex(std::ofstream* out, const std::string& name,
        << "      sizeof(" << name << "_raw));\n";
   *out << std::dec;  // Turn off hex when we're done.
 }
+
+void LogTimer(const char* field, bool set, int64_t time) {
+  long long total_seconds = static_cast<long long>(time);
+  char sign = ' ';
+  if (total_seconds < 0) {
+    total_seconds = -total_seconds;
+    sign = '-';
+  }
+  const unsigned long long seconds = total_seconds % 60;
+  unsigned long long minutes = total_seconds / 60;
+  unsigned long long hours = minutes / 60;
+  minutes = minutes % 60;
+  unsigned long long days = hours / 24;
+  hours = hours % 24;
+  if (set) {
+    LOGD("%25.25s: %c%llu seconds = %llu day %02llu:%02llu:%02llu HMS", field,
+         sign, total_seconds, days, hours, minutes, seconds);
+  } else {
+    LOGD("%25.25s: %llu seconds (unset)", field, total_seconds);
+  }
+}
+
+void PrintRequestProto(const char* label,
+                       const video_widevine::LicenseRequest& request) {
+  switch (request.type()) {
+    case video_widevine::LicenseRequest_RequestType_NEW:
+      LOGD("%s type: NEW", label);
+      break;
+    case video_widevine::LicenseRequest_RequestType_RENEWAL:
+      LOGD("%s type: RENEWAL", label);
+      break;
+    case video_widevine::LicenseRequest_RequestType_RELEASE:
+      LOGD("%s type: RELEASE", label);
+      break;
+  }
+}
+void PrintLicenseProto(const char* label,
+                       const video_widevine::License& license) {
+  LOGD("%s: can_play = %s, can_persist = %s, can_renew = %s", label,
+       license.policy().can_play() ? "true" : "false",
+       license.policy().can_persist() ? "true" : "false",
+       license.policy().can_renew() ? "true" : "false");
+#define QUOTE_DEFINE(A) #A
+#define QUOTE(A) QUOTE_DEFINE(A)
+#define LOG_TIMER(NAME) \
+  LogTimer(QUOTE(NAME), license.policy().has_##NAME(), license.policy().NAME())
+  LOG_TIMER(rental_duration_seconds);
+  LOG_TIMER(playback_duration_seconds);
+  LOG_TIMER(license_duration_seconds);
+  LOG_TIMER(renewal_recovery_duration_seconds);
+  LOG_TIMER(renewal_delay_seconds);
+  LOG_TIMER(renewal_retry_interval_seconds);
+  LOGD("renewal_server_url: %s", license.policy().renewal_server_url().c_str());
+  LOGD("renew_with_usage: %s",
+       license.policy().renew_with_usage() ? "true" : "false");
+  LOG_TIMER(play_start_grace_period_seconds);
+}
 }  // namespace
 
 std::ofstream MessageDumper::license_file;
@@ -75,28 +132,37 @@ void MessageDumper::DumpLicenseRequest(const CdmKeyRequest& request) {
   SignedMessage signed_message;
   DumpHeader(&license_file, "License");
   EXPECT_TRUE(signed_message.ParseFromString(request.message));
+  if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
     EXPECT_TRUE(signed_message.has_oemcrypto_core_message());
     DumpHex(&license_file, "core_request",
             signed_message.oemcrypto_core_message());
+  }
   // Since this is run within a test, we can also verify that the
   // request is valid.
   video_widevine::LicenseRequest license_request;
   EXPECT_TRUE(license_request.ParseFromString(signed_message.msg()));
+  // TODO(fredgc): figure out if we can build tests with full protobufs instead
+  // of proto lite, so that we can use TextFormat.
+  PrintRequestProto("License Request", license_request);
 }
 
 void MessageDumper::DumpLicense(const std::string& response) {
   SignedMessage signed_response;
   EXPECT_TRUE(signed_response.ParseFromString(response));
+  if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
     EXPECT_TRUE(signed_response.has_oemcrypto_core_message());
     DumpHex(&license_file, "core_response",
             signed_response.oemcrypto_core_message());
+  }
 
   video_widevine::License license;
   EXPECT_TRUE(license.ParseFromString(signed_response.msg()));
+  PrintLicenseProto("License", license);
   DumpHex(&license_file, "serialized_license", signed_response.msg());
 
   std::string message =
       signed_response.oemcrypto_core_message() + signed_response.msg();
+  if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
     ODK_Message odk_msg = ODK_Message_Create(
         reinterpret_cast<uint8_t*>(const_cast<char*>(message.c_str())),
         message.length());
@@ -113,6 +179,7 @@ void MessageDumper::DumpLicense(const std::string& response) {
     license_file << "  nonce_required_ = "
                  << (odk_parsed_license.nonce_required ? "true" : "false")
                  << ";\n";
+  }
   license_file << "  RunTest();\n";
   license_file << "}\n\n";
 }
@@ -121,26 +188,31 @@ void MessageDumper::DumpRenewalRequest(const CdmKeyRequest& request) {
   DumpHeader(&renewal_file, "Renewal");
   SignedMessage signed_message;
   EXPECT_TRUE(signed_message.ParseFromString(request.message));
+  if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
     EXPECT_TRUE(signed_message.has_oemcrypto_core_message());
     DumpHex(&renewal_file, "core_request",
             signed_message.oemcrypto_core_message());
-
+  }
   video_widevine::LicenseRequest renewal_request;
   EXPECT_TRUE(renewal_request.ParseFromString(signed_message.msg()));
+  PrintRequestProto("Renewal Request", renewal_request);
 }
 
 void MessageDumper::DumpRenewal(const std::string& response) {
   SignedMessage signed_response;
   EXPECT_TRUE(signed_response.ParseFromString(response))
       << "Response = " << wvutil::b2a_hex(response);
+  if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
     EXPECT_TRUE(signed_response.has_oemcrypto_core_message());
     DumpHex(&renewal_file, "core_response",
             signed_response.oemcrypto_core_message());
-
+  }
   video_widevine::License renewal;
   EXPECT_TRUE(renewal.ParseFromString(signed_response.msg()));
+  PrintLicenseProto("Renewal", renewal);
   DumpHex(&renewal_file, "renewal", signed_response.msg());
 
+  if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
     std::string message =
         signed_response.oemcrypto_core_message() + signed_response.msg();
     ODK_Message odk_msg = ODK_Message_Create(
@@ -153,6 +225,7 @@ void MessageDumper::DumpRenewal(const std::string& response) {
     EXPECT_EQ(ODK_Message_GetStatus(&odk_msg), MESSAGE_STATUS_OK);
     renewal_file << "  renewal_duration_seconds_ = "
                  << odk_renewal_response.renewal_duration_seconds << ";\n";
+  }
   renewal_file << "  RunTest();\n";
   renewal_file << "}\n\n";
 }
@@ -167,11 +240,13 @@ void MessageDumper::DumpProvisioningRequest(
     SignedProvisioningMessage signed_message;
     EXPECT_TRUE(signed_message.ParseFromString(request))
         << "Request = " << wvutil::b2a_hex(request);
+    if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
       EXPECT_TRUE(signed_message.has_oemcrypto_core_message());
       DumpHex(&provision_file, "core_request",
               signed_message.oemcrypto_core_message());
     }
   }
+}
 
 void MessageDumper::DumpProvisioning(const CdmProvisioningResponse& response) {
   if (wvoec::global_features.derive_key_method ==
@@ -186,9 +261,11 @@ void MessageDumper::DumpProvisioning(const CdmProvisioningResponse& response) {
           response, &extracted_message));
       EXPECT_TRUE(signed_response.ParseFromString(extracted_message));
     }
+    if (wvoec::global_features.api_version >= wvoec::kCoreMessagesAPI) {
       EXPECT_TRUE(signed_response.has_oemcrypto_core_message());
       DumpHex(&provision_file, "core_response",
               signed_response.oemcrypto_core_message());
+    }
     DumpHex(&provision_file, "provisioning_response",
             signed_response.message());
     // The choice of ECC or RSA key is decided at the server, based on