diff --git a/libwvdrmengine/cdm/core/include/cdm_session.h b/libwvdrmengine/cdm/core/include/cdm_session.h index e14cc797..58f55668 100644 --- a/libwvdrmengine/cdm/core/include/cdm_session.h +++ b/libwvdrmengine/cdm/core/include/cdm_session.h @@ -199,6 +199,12 @@ class CdmSession { bool UpdateUsageInfo(); + CdmResponseType GenerateKeyRequestInternal( + const InitializationData& init_data, CdmLicenseType license_type, + const CdmAppParameterMap& app_parameters, CdmKeyRequest* key_request); + virtual CdmResponseType AddKeyInternal(const CdmKeyResponse& key_response); + void UpdateRequestLatencyTiming(CdmResponseType sts); + // These setters are for testing only. Takes ownership of the pointers. void set_license_parser(CdmLicense* license_parser); void set_crypto_session(CryptoSession* crypto_session); @@ -209,6 +215,8 @@ class CdmSession { metrics::SessionMetrics* metrics_; metrics::CryptoMetrics* crypto_metrics_; metrics::TimerMetric life_span_; + metrics::TimerMetric license_request_latency_; + CdmKeyRequestType key_request_type_; bool initialized_; bool closed_; // Session closed, but final shared_ptr has not been released. diff --git a/libwvdrmengine/cdm/core/src/cdm_session.cpp b/libwvdrmengine/cdm/core/src/cdm_session.cpp index a0378696..5cb77013 100644 --- a/libwvdrmengine/cdm/core/src/cdm_session.cpp +++ b/libwvdrmengine/cdm/core/src/cdm_session.cpp @@ -324,7 +324,23 @@ CdmResponseType CdmSession::RestoreUsageSession( return KEY_ADDED; } +// This is a thin wrapper that initiates the latency metric. CdmResponseType CdmSession::GenerateKeyRequest( + const InitializationData& init_data, CdmLicenseType license_type, + const CdmAppParameterMap& app_parameters, CdmKeyRequest* key_request) { + CdmResponseType result = GenerateKeyRequestInternal( + init_data, license_type, app_parameters, key_request); + // Note that GenerateReleaseRequest and GenerateRenewalRequest will initialize + // the timer themselves. This is duplicate because there are duplicate paths + // for calling GenerateReleaseRequest and GenerateRenewalRequest. + if (result == KEY_MESSAGE) { + key_request_type_ = key_request->type; + license_request_latency_.Start(); // Start or restart timer. + } + return result; +} + +CdmResponseType CdmSession::GenerateKeyRequestInternal( const InitializationData& init_data, CdmLicenseType license_type, const CdmAppParameterMap& app_parameters, CdmKeyRequest* key_request) { @@ -410,8 +426,15 @@ CdmResponseType CdmSession::GenerateKeyRequest( } } -// AddKey() - Accept license response and extract key info. +// This thin wrapper allows us to update metrics. CdmResponseType CdmSession::AddKey(const CdmKeyResponse& key_response) { + CdmResponseType sts = AddKeyInternal(key_response); + UpdateRequestLatencyTiming(sts); + return sts; +} + +// AddKeyInternal() - Accept license response and extract key info. +CdmResponseType CdmSession::AddKeyInternal(const CdmKeyResponse& key_response) { if (!initialized_) { LOGE("CdmSession::AddKey: not initialized"); return NOT_INITIALIZED_ERROR; @@ -602,6 +625,8 @@ CdmResponseType CdmSession::GenerateRenewalRequest( if (is_offline_) { offline_key_renewal_request_ = key_request->message; } + key_request_type_ = key_request->type; + license_request_latency_.Start(); // Start or restart timer. return KEY_MESSAGE; } @@ -613,6 +638,10 @@ CdmResponseType CdmSession::RenewKey(const CdmKeyResponse& key_response) { } CdmResponseType sts = license_parser_->HandleKeyUpdateResponse(true, key_response); + + // Record the timing on success. + UpdateRequestLatencyTiming(sts); + if (sts != KEY_ADDED) return (sts == KEY_ERROR) ? RENEW_KEY_ERROR_1 : sts; if (is_offline_) { @@ -630,6 +659,7 @@ CdmResponseType CdmSession::GenerateReleaseRequest( return NOT_INITIALIZED_ERROR; } is_release_ = true; + license_request_latency_.Clear(); CdmResponseType status = license_parser_->PrepareKeyUpdateRequest( false, app_parameters_, usage_table_header_ == NULL ? NULL : this, &key_request->message, &key_request->url); @@ -658,6 +688,10 @@ CdmResponseType CdmSession::GenerateReleaseRequest( return RELEASE_USAGE_INFO_FAILED; } } + + key_request_type_ = key_request->type; + license_request_latency_.Start(); // Start or restart timer. + return KEY_MESSAGE; } @@ -669,6 +703,9 @@ CdmResponseType CdmSession::ReleaseKey(const CdmKeyResponse& key_response) { } CdmResponseType sts = license_parser_->HandleKeyUpdateResponse(false, key_response); + // Record the timing on success. + UpdateRequestLatencyTiming(sts); + if (sts != KEY_ADDED) return (sts == KEY_ERROR) ? RELEASE_KEY_ERROR : sts; if (is_offline_ || has_provider_session_token()) { @@ -1046,6 +1083,14 @@ bool CdmSession::UpdateUsageInfo() { usage_data); } +void CdmSession::UpdateRequestLatencyTiming(CdmResponseType sts) { + if (sts == KEY_ADDED && license_request_latency_.IsStarted()) { + metrics_->cdm_session_license_request_latency_ms_.Record( + license_request_latency_.AsMs(), key_request_type_); + } + license_request_latency_.Clear(); +} + // For testing only - takes ownership of pointers void CdmSession::set_license_parser(CdmLicense* license_parser) { diff --git a/libwvdrmengine/cdm/core/test/cdm_engine_test.cpp b/libwvdrmengine/cdm/core/test/cdm_engine_test.cpp index 89fad2b5..4e5232a0 100644 --- a/libwvdrmengine/cdm/core/test/cdm_engine_test.cpp +++ b/libwvdrmengine/cdm/core/test/cdm_engine_test.cpp @@ -15,6 +15,7 @@ #include "file_store.h" #include "license_request.h" #include "log.h" +#include "metrics.pb.h" #include "OEMCryptoCENC.h" #include "properties.h" #include "scoped_ptr.h" @@ -26,6 +27,9 @@ namespace wvcdm { +using drm_metrics::WvCdmMetrics; +using drm_metrics::DistributionMetric; + namespace { // Http OK response code. @@ -460,12 +464,43 @@ class WvCdmEngineTest : public WvCdmEnginePreProvTest { CdmKeySetId key_set_id; EXPECT_EQ(KEY_ADDED, cdm_engine_.AddKey(session_id_, resp, &key_set_id)); + VerifyLicenseRequestLatency(CdmKeyRequestType::kKeyRequestTypeInitial, + *cdm_engine_.GetMetrics()); } void VerifyRenewalKeyResponse(const std::string& server_url, const std::string& client_auth) { std::string resp = GetKeyRequestResponse(server_url, client_auth); EXPECT_EQ(KEY_ADDED, cdm_engine_.RenewKey(session_id_, resp)); + VerifyLicenseRequestLatency(CdmKeyRequestType::kKeyRequestTypeRenewal, + *cdm_engine_.GetMetrics()); + } + + void VerifyLicenseRequestLatency( + CdmKeyRequestType key_request_type, + const metrics::EngineMetrics& engine_metrics) { + WvCdmMetrics metrics_proto; + engine_metrics.Serialize(&metrics_proto); + bool has_request_type = false; + for (int i = 0; i < metrics_proto.session_metrics_size(); i++) { + WvCdmMetrics::SessionMetrics session_metrics = + metrics_proto.session_metrics(i); + for (int j = 0; + j < session_metrics.cdm_session_license_request_latency_ms_size(); + j++) { + DistributionMetric latency_distribution = + session_metrics.cdm_session_license_request_latency_ms(j); + if (latency_distribution.attributes().key_request_type() + == key_request_type && latency_distribution.operation_count() > 0) { + has_request_type = true; + } + } + } + std::string serialized_metrics; + ASSERT_TRUE(metrics_proto.SerializeToString(&serialized_metrics)); + EXPECT_TRUE(has_request_type) + << "Expected request type " << key_request_type << " was not found. " + << "metrics: " << wvcdm::b2a_hex(serialized_metrics); } std::string server_url_; diff --git a/libwvdrmengine/cdm/metrics/include/counter_metric.h b/libwvdrmengine/cdm/metrics/include/counter_metric.h index 0b21acb3..da4d5f95 100644 --- a/libwvdrmengine/cdm/metrics/include/counter_metric.h +++ b/libwvdrmengine/cdm/metrics/include/counter_metric.h @@ -106,7 +106,7 @@ class CounterMetric : public BaseCounterMetric { } void ToProto(::google::protobuf::RepeatedPtrField - *counters); + *counters) const; private: friend class CounterMetricTest; @@ -121,7 +121,7 @@ template <> inline void CounterMetric<0, util::Unused, 0, util::Unused, 0, util::Unused, 0, util::Unused>:: ToProto(::google::protobuf::RepeatedPtrField - *counters) { + *counters) const { const std::map* values = GetValues(); for (std::map::const_iterator it = values->begin(); @@ -135,7 +135,7 @@ template inline void CounterMetric::ToProto( ::google::protobuf::RepeatedPtrField - *counters) { + *counters) const { const std::map* values = GetValues(); for (std::map::const_iterator it = values->begin(); it != values->end(); it++) { diff --git a/libwvdrmengine/cdm/metrics/include/event_metric.h b/libwvdrmengine/cdm/metrics/include/event_metric.h index a1142055..52fb1c24 100644 --- a/libwvdrmengine/cdm/metrics/include/event_metric.h +++ b/libwvdrmengine/cdm/metrics/include/event_metric.h @@ -110,7 +110,7 @@ class EventMetric : public BaseEventMetric { void ToProto( ::google::protobuf::RepeatedPtrField - *distributions_proto); + *distributions_proto) const; private: friend class EventMetricTest; @@ -118,7 +118,7 @@ class EventMetric : public BaseEventMetric { inline void SetDistributionValues( const Distribution &distribution, - drm_metrics::DistributionMetric *metric_proto) { + drm_metrics::DistributionMetric *metric_proto) const { metric_proto->set_mean(distribution.Mean()); metric_proto->set_operation_count(distribution.Count()); if (distribution.Count() > 1) { @@ -140,7 +140,7 @@ inline void EventMetric<0, util::Unused, 0, util::Unused, 0, util::Unused, 0, util::Unused>:: ToProto( ::google::protobuf::RepeatedPtrField - *distributions_proto) { + *distributions_proto) const { const std::map* distributions = GetDistributions(); for (std::map::const_iterator it = @@ -154,7 +154,7 @@ template inline void EventMetric::ToProto( ::google::protobuf::RepeatedPtrField - *distributions_proto) { + *distributions_proto) const { const std::map* distributions = GetDistributions(); for (std::map::const_iterator it = diff --git a/libwvdrmengine/cdm/metrics/include/metrics_collections.h b/libwvdrmengine/cdm/metrics/include/metrics_collections.h index 3d140a1a..141e9695 100644 --- a/libwvdrmengine/cdm/metrics/include/metrics_collections.h +++ b/libwvdrmengine/cdm/metrics/include/metrics_collections.h @@ -82,6 +82,8 @@ const int kKeyStatusTypeFieldNumber = ::drm_metrics::Attributes::kKeyStatusTypeFieldNumber; const int kEventTypeFieldNumber = ::drm_metrics::Attributes::kEventTypeFieldNumber; +const int kKeyRequestTypeFieldNumber = + ::drm_metrics::Attributes::kKeyRequestTypeFieldNumber; } // anonymous namespace @@ -111,7 +113,8 @@ typedef enum OEMCryptoInitializationMode { // This class contains metrics for Crypto Session and OEM Crypto. class CryptoMetrics { public: - void Serialize(drm_metrics::WvCdmMetrics::CryptoMetrics *crypto_metrics); + void Serialize(drm_metrics::WvCdmMetrics::CryptoMetrics *crypto_metrics) + const; /* CRYPTO SESSION */ // TODO(blueeyes): Convert this to crypto_session_default_security_level_. @@ -267,13 +270,17 @@ class SessionMetrics { CounterMetric cdm_session_restore_usage_session_; + EventMetric + cdm_session_license_request_latency_ms_; + // Serialize the session metrics to the provided |metric_group|. // |metric_group| is owned by the caller and must not be null. - void Serialize(drm_metrics::WvCdmMetrics::SessionMetrics *session_metrics); + void Serialize(drm_metrics::WvCdmMetrics::SessionMetrics *session_metrics) + const; private: void SerializeSessionMetrics( - drm_metrics::WvCdmMetrics::SessionMetrics *session_metrics); + drm_metrics::WvCdmMetrics::SessionMetrics *session_metrics) const; CdmSessionId session_id_; bool completed_; CryptoMetrics crypto_metrics_; @@ -299,13 +306,14 @@ class OemCryptoDynamicAdapterMetrics { // Serialize the session metrics to the provided |metric_group|. // |metric_group| is owned by the caller and must not be null. - void Serialize(drm_metrics::WvCdmMetrics::EngineMetrics *engine_metrics); + void Serialize(drm_metrics::WvCdmMetrics::EngineMetrics *engine_metrics) + const; // Clears the existing metric values. void Clear(); private: - Lock adapter_lock_; + mutable Lock adapter_lock_; ValueMetric oemcrypto_initialization_mode_; ValueMetric oemcrypto_l1_api_version_; ValueMetric oemcrypto_l1_min_api_version_; @@ -351,7 +359,7 @@ class EngineMetrics { // void Serialize(drm_metrics::MetricsGroup* metric_group, bool // completed_only, // bool clear_serialized_sessions); - void Serialize(drm_metrics::WvCdmMetrics *engine_metrics); + void Serialize(drm_metrics::WvCdmMetrics *engine_metrics) const; void SetAppPackageName(const std::string &app_package_name); @@ -397,7 +405,7 @@ class EngineMetrics { cdm_engine_unprovision_; private: - Lock session_metrics_lock_; + mutable Lock session_metrics_lock_; std::vector session_metrics_list_; // This is used to populate the engine lifespan metric metrics::TimerMetric life_span_internal_; @@ -405,7 +413,7 @@ class EngineMetrics { std::string app_package_name_; void SerializeEngineMetrics( - drm_metrics::WvCdmMetrics::EngineMetrics *engine_metrics); + drm_metrics::WvCdmMetrics::EngineMetrics *engine_metrics) const; }; } // namespace metrics diff --git a/libwvdrmengine/cdm/metrics/include/timer_metric.h b/libwvdrmengine/cdm/metrics/include/timer_metric.h index ce00c2fd..84a8d20a 100644 --- a/libwvdrmengine/cdm/metrics/include/timer_metric.h +++ b/libwvdrmengine/cdm/metrics/include/timer_metric.h @@ -9,13 +9,23 @@ namespace metrics { class TimerMetric { public: + // Starts the clock running. If the clock was previously set, this resets it. + // IsStarted will return true after this call. void Start(); + // Returns whether or not the timer has started. + bool IsStarted() const { return is_started_; }; + // Stops the clock and clears the current value. IsStarted will return false + // after this call. + void Clear(); + // Returns the current clock value as milliseconds (AsMs) or microseconds + // (AsUs). double AsMs() const; double AsUs() const; private: double sec_; double usec_; + bool is_started_; }; diff --git a/libwvdrmengine/cdm/metrics/include/value_metric.h b/libwvdrmengine/cdm/metrics/include/value_metric.h index 5982439a..360e1dbc 100644 --- a/libwvdrmengine/cdm/metrics/include/value_metric.h +++ b/libwvdrmengine/cdm/metrics/include/value_metric.h @@ -72,7 +72,7 @@ class ValueMetric { // Returns a new ValueMetric proto containing the metric value or the // error code. If neither the error or value are set, it returns nullptr. - drm_metrics::ValueMetric *ToProto() { + drm_metrics::ValueMetric *ToProto() const { if (has_error_) { drm_metrics::ValueMetric *value_proto = new drm_metrics::ValueMetric; value_proto->set_error_code(error_code_); diff --git a/libwvdrmengine/cdm/metrics/src/attribute_handler.cpp b/libwvdrmengine/cdm/metrics/src/attribute_handler.cpp index 6f295881..8de1a641 100644 --- a/libwvdrmengine/cdm/metrics/src/attribute_handler.cpp +++ b/libwvdrmengine/cdm/metrics/src/attribute_handler.cpp @@ -72,6 +72,14 @@ void SetAttributeFieldset_signing_algorithm(signing_algorithm); } +template <> +void SetAttributeField( + const CdmKeyRequestType &key_request_type, + drm_metrics::Attributes *attributes) { + attributes->set_key_request_type(key_request_type); +} + template <> void SetAttributeField<0, util::Unused>(const util::Unused &, drm_metrics::Attributes *) { diff --git a/libwvdrmengine/cdm/metrics/src/metrics.proto b/libwvdrmengine/cdm/metrics/src/metrics.proto index 0f79cce7..680d35e6 100644 --- a/libwvdrmengine/cdm/metrics/src/metrics.proto +++ b/libwvdrmengine/cdm/metrics/src/metrics.proto @@ -44,6 +44,8 @@ message Attributes { optional uint32 key_status_type = 14; // Defined at ::android::hardware::drm::V1_0::EventType; optional uint32 event_type = 15; + // Contains the CdmKeyRequestType defined in wv_cdm_types.h. + optional uint32 key_request_type = 16; } // The Counter message is used to store a count value with an associated @@ -153,7 +155,7 @@ message WvCdmMetrics { // This contains metrics that were captured within a CdmSession. This contains // nested CryptoMetrics that were captured in the context of the session. - // next id: 7 + // next id: 8 message SessionMetrics { optional ValueMetric session_id = 1; optional CryptoMetrics crypto_metrics = 2; @@ -161,6 +163,7 @@ message WvCdmMetrics { repeated DistributionMetric cdm_session_renew_key_time_us = 4; repeated CounterMetric cdm_session_restore_offline_session = 5; repeated CounterMetric cdm_session_restore_usage_session = 6; + repeated DistributionMetric cdm_session_license_request_latency_ms = 7; } // These are metrics recorded at the Engine level. This includes CryptoSession diff --git a/libwvdrmengine/cdm/metrics/src/metrics_collections.cpp b/libwvdrmengine/cdm/metrics/src/metrics_collections.cpp index 9e19dd7d..b3b28448 100644 --- a/libwvdrmengine/cdm/metrics/src/metrics_collections.cpp +++ b/libwvdrmengine/cdm/metrics/src/metrics_collections.cpp @@ -29,7 +29,8 @@ struct CompareSessionIds { namespace wvcdm { namespace metrics { -void CryptoMetrics::Serialize(WvCdmMetrics::CryptoMetrics *crypto_metrics) { +void CryptoMetrics::Serialize(WvCdmMetrics::CryptoMetrics *crypto_metrics) + const { /* CRYPTO SESSION */ crypto_metrics->set_allocated_crypto_session_security_level( crypto_session_security_level_.ToProto()); @@ -151,20 +152,16 @@ void CryptoMetrics::Serialize(WvCdmMetrics::CryptoMetrics *crypto_metrics) { crypto_metrics->mutable_oemcrypto_update_usage_entry()); } -SessionMetrics::SessionMetrics() - : cdm_session_life_span_(), - cdm_session_renew_key_(), - cdm_session_restore_offline_session_(), - cdm_session_restore_usage_session_(), - completed_(false) {} +SessionMetrics::SessionMetrics() {} -void SessionMetrics::Serialize(WvCdmMetrics::SessionMetrics *session_metrics) { +void SessionMetrics::Serialize(WvCdmMetrics::SessionMetrics *session_metrics) + const { SerializeSessionMetrics(session_metrics); crypto_metrics_.Serialize(session_metrics->mutable_crypto_metrics()); } void SessionMetrics::SerializeSessionMetrics( - WvCdmMetrics::SessionMetrics *session_metrics) { + WvCdmMetrics::SessionMetrics *session_metrics) const { // If the session id was set, add it to the metrics. It's possible that // it's not set in some circumstances such as when provisioning is needed. if (!session_id_.empty()) { @@ -178,6 +175,8 @@ void SessionMetrics::SerializeSessionMetrics( session_metrics->mutable_cdm_session_restore_offline_session()); cdm_session_restore_usage_session_.ToProto( session_metrics->mutable_cdm_session_restore_usage_session()); + cdm_session_license_request_latency_ms_.ToProto( + session_metrics->mutable_cdm_session_license_request_latency_ms()); } OemCryptoDynamicAdapterMetrics::OemCryptoDynamicAdapterMetrics() @@ -202,7 +201,7 @@ void OemCryptoDynamicAdapterMetrics::SetL1MinApiVersion(uint32_t version) { } void OemCryptoDynamicAdapterMetrics::Serialize( - WvCdmMetrics::EngineMetrics *engine_metrics) { + WvCdmMetrics::EngineMetrics *engine_metrics) const { AutoLock lock(adapter_lock_); engine_metrics->set_allocated_oemcrypto_initialization_mode( @@ -264,7 +263,7 @@ void EngineMetrics::RemoveSession(wvcdm::CdmSessionId session_id) { session_metrics_list_.end()); } -void EngineMetrics::Serialize(WvCdmMetrics *wv_metrics) { +void EngineMetrics::Serialize(WvCdmMetrics *wv_metrics) const { AutoLock lock(session_metrics_lock_); WvCdmMetrics::EngineMetrics *engine_metrics = wv_metrics->mutable_engine_metrics(); @@ -291,7 +290,7 @@ void EngineMetrics::SetAppPackageName(const std::string &app_package_name) { } void EngineMetrics::SerializeEngineMetrics( - WvCdmMetrics::EngineMetrics *engine_metrics) { + WvCdmMetrics::EngineMetrics *engine_metrics) const { // Set the engine lifespan at the time of serialization. engine_metrics->mutable_cdm_engine_life_span_ms()->set_int_value( life_span_internal_.AsMs()); diff --git a/libwvdrmengine/cdm/metrics/src/timer_metric.cpp b/libwvdrmengine/cdm/metrics/src/timer_metric.cpp index f1990949..03575567 100644 --- a/libwvdrmengine/cdm/metrics/src/timer_metric.cpp +++ b/libwvdrmengine/cdm/metrics/src/timer_metric.cpp @@ -11,6 +11,13 @@ void TimerMetric::Start() { gettimeofday(&tv, NULL); sec_ = tv.tv_sec; usec_ = tv.tv_usec; + is_started_ = true; +} + +void TimerMetric::Clear() { + is_started_ = false; + sec_ = 0; + usec_ = 0; } double TimerMetric::AsMs() const {