Add logging support for FW metrics
Adds proto serialization and logging support for media drm framework metrics.
Bug: 64001676
Test: Ran CTS tests, unit tests and Google Play.
Change-Id: Ie350ac93caa6b35610eb63e4acc860c8e8a5cf5b
diff --git a/drm/libmediadrm/tests/DrmMetrics_test.cpp b/drm/libmediadrm/tests/DrmMetrics_test.cpp
index d774eae..fe762c9 100644
--- a/drm/libmediadrm/tests/DrmMetrics_test.cpp
+++ b/drm/libmediadrm/tests/DrmMetrics_test.cpp
@@ -14,21 +14,40 @@
* limitations under the License.
*/
-#include <binder/PersistableBundle.h>
-#include <gtest/gtest.h>
-
+#define LOG_TAG "DrmMetricsTest"
#include "DrmMetrics.h"
+#include <binder/PersistableBundle.h>
+#include <google/protobuf/text_format.h>
+#include <google/protobuf/util/message_differencer.h>
+#include <gtest/gtest.h>
+#include <utils/Log.h>
+
+#include "protos/metrics.pb.h"
+
+using ::android::drm_metrics::DrmFrameworkMetrics;
using ::android::hardware::drm::V1_0::EventType;
using ::android::hardware::drm::V1_0::KeyStatusType;
using ::android::os::PersistableBundle;
+using ::google::protobuf::util::MessageDifferencer;
+using ::google::protobuf::TextFormat;
namespace android {
/**
* Unit tests for the MediaDrmMetrics class.
*/
-class MediaDrmMetricsTest : public ::testing::Test {
+class MediaDrmMetricsTest : public ::testing::Test {};
+
+/**
+ * This derived class mocks the clock for testing purposes.
+ */
+class FakeMediaDrmMetrics : public MediaDrmMetrics {
+ public:
+ FakeMediaDrmMetrics() : MediaDrmMetrics(), time_(0) {};
+
+ int64_t GetCurrentTimeMs() { return time_++; }
+ int64_t time_;
};
TEST_F(MediaDrmMetricsTest, EmptySuccess) {
@@ -46,9 +65,9 @@
metrics.mCloseSessionCounter.Increment(OK);
{
- EventTimer<status_t> get_key_request_timer(&metrics.mGetKeyRequestTiming);
+ EventTimer<status_t> get_key_request_timer(&metrics.mGetKeyRequestTimeUs);
EventTimer<status_t> provide_key_response_timer(
- &metrics.mProvideKeyResponseTiming);
+ &metrics.mProvideKeyResponseTimeUs);
get_key_request_timer.SetAttribute(OK);
provide_key_response_timer.SetAttribute(OK);
}
@@ -109,9 +128,9 @@
for (status_t s : {OK, UNEXPECTED_NULL}) {
{
- EventTimer<status_t> get_key_request_timer(&metrics.mGetKeyRequestTiming);
+ EventTimer<status_t> get_key_request_timer(&metrics.mGetKeyRequestTimeUs);
EventTimer<status_t> provide_key_response_timer(
- &metrics.mProvideKeyResponseTiming);
+ &metrics.mProvideKeyResponseTimeUs);
get_key_request_timer.SetAttribute(s);
provide_key_response_timer.SetAttribute(s);
}
@@ -135,9 +154,23 @@
metrics.mEventCounter.Increment(EventType::VENDOR_DEFINED);
metrics.mEventCounter.Increment(EventType::SESSION_RECLAIMED);
+ android::Vector<uint8_t> sessionId1;
+ sessionId1.push_back(1);
+ sessionId1.push_back(2);
+ android::Vector<uint8_t> sessionId2;
+ sessionId2.push_back(3);
+ sessionId2.push_back(4);
+ String16 hexSessionId1("0102");
+ String16 hexSessionId2("0304");
+
+ metrics.SetSessionStart(sessionId1);
+ metrics.SetSessionStart(sessionId2);
+ metrics.SetSessionEnd(sessionId2);
+ metrics.SetSessionEnd(sessionId1);
+
PersistableBundle bundle;
metrics.Export(&bundle);
- EXPECT_EQ(33U, bundle.size());
+ EXPECT_EQ(35U, bundle.size());
// Verify the list of pairs of int64 metrics.
std::vector<std::pair<std::string, int64_t>> expected_values = {
@@ -194,6 +227,25 @@
}
}
+ // Verify the lifespans
+ PersistableBundle start_times;
+ PersistableBundle end_times;
+ String16 start_time_key("drm.mediadrm.session_start_times_ms");
+ String16 end_time_key("drm.mediadrm.session_end_times_ms");
+ ASSERT_TRUE(bundle.getPersistableBundle(start_time_key, &start_times));
+ ASSERT_TRUE(bundle.getPersistableBundle(end_time_key, &end_times));
+ EXPECT_EQ(2U, start_times.size());
+ EXPECT_EQ(2U, end_times.size());
+ int64_t start_time, end_time;
+ for (const auto& sid : { hexSessionId1, hexSessionId2 }) {
+ start_time = -1;
+ end_time = -1;
+ EXPECT_TRUE(start_times.getLong(sid, &start_time));
+ EXPECT_TRUE(end_times.getLong(sid, &end_time));
+ EXPECT_GT(start_time, 0);
+ EXPECT_GE(end_time, start_time);
+ }
+
// Validate timing values exist.
String16 get_key_request_key(
"drm.mediadrm.get_key_request.ok.average_time_micros");
@@ -207,4 +259,157 @@
EXPECT_GE(value, 0);
}
+
+TEST_F(MediaDrmMetricsTest, CounterValuesProtoSerialization) {
+ MediaDrmMetrics metrics;
+
+ metrics.mOpenSessionCounter.Increment(OK);
+ metrics.mOpenSessionCounter.Increment(UNEXPECTED_NULL);
+ metrics.mCloseSessionCounter.Increment(OK);
+ metrics.mCloseSessionCounter.Increment(UNEXPECTED_NULL);
+
+ metrics.mGetProvisionRequestCounter.Increment(OK);
+ metrics.mGetProvisionRequestCounter.Increment(UNEXPECTED_NULL);
+ metrics.mProvideProvisionResponseCounter.Increment(OK);
+ metrics.mProvideProvisionResponseCounter.Increment(UNEXPECTED_NULL);
+ metrics.mGetDeviceUniqueIdCounter.Increment(OK);
+ metrics.mGetDeviceUniqueIdCounter.Increment(UNEXPECTED_NULL);
+
+ metrics.mKeyStatusChangeCounter.Increment(KeyStatusType::USABLE);
+ metrics.mKeyStatusChangeCounter.Increment(KeyStatusType::EXPIRED);
+ metrics.mKeyStatusChangeCounter.Increment(KeyStatusType::OUTPUTNOTALLOWED);
+ metrics.mKeyStatusChangeCounter.Increment(KeyStatusType::STATUSPENDING);
+ metrics.mKeyStatusChangeCounter.Increment(KeyStatusType::INTERNALERROR);
+ metrics.mEventCounter.Increment(EventType::PROVISION_REQUIRED);
+ metrics.mEventCounter.Increment(EventType::KEY_NEEDED);
+ metrics.mEventCounter.Increment(EventType::KEY_EXPIRED);
+ metrics.mEventCounter.Increment(EventType::VENDOR_DEFINED);
+ metrics.mEventCounter.Increment(EventType::SESSION_RECLAIMED);
+
+ std::string serializedMetrics;
+ ASSERT_EQ(OK, metrics.GetSerializedMetrics(&serializedMetrics));
+
+ DrmFrameworkMetrics metricsProto;
+ ASSERT_TRUE(metricsProto.ParseFromString(serializedMetrics));
+
+ std::string expectedMetrics =
+ "open_session_counter { count: 1 attributes { error_code: -0x7FFFFFF8 } } "
+ "open_session_counter { count: 1 attributes { error_code: 0 } } "
+ "close_session_counter { count: 1 attributes { error_code: -0x7FFFFFF8 } } "
+ "close_session_counter { count: 1 attributes { error_code: 0 } } "
+ "get_provisioning_request_counter { count: 1 attributes { error_code: -0x7FFFFFF8 } } "
+ "get_provisioning_request_counter { count: 1 attributes { error_code: 0 } } "
+ "provide_provisioning_response_counter { count: 1 attributes { error_code: -0x7ffffff8 } } "
+ "provide_provisioning_response_counter { count: 1 attributes { error_code: 0 } } "
+ "get_device_unique_id_counter { count: 1 attributes { error_code: -0x7ffffff8 } } "
+ "get_device_unique_id_counter { count: 1 attributes { error_code: 0 } } "
+ "key_status_change_counter { count: 1 attributes { key_status_type: 0 } } "
+ "key_status_change_counter { count: 1 attributes { key_status_type: 1 } } "
+ "key_status_change_counter { count: 1 attributes { key_status_type: 2 } } "
+ "key_status_change_counter { count: 1 attributes { key_status_type: 3 } } "
+ "key_status_change_counter { count: 1 attributes { key_status_type: 4 } } "
+ "event_callback_counter { count: 1 attributes { event_type: 0 } } "
+ "event_callback_counter { count: 1 attributes { event_type: 1 } } "
+ "event_callback_counter { count: 1 attributes { event_type: 2 } } "
+ "event_callback_counter { count: 1 attributes { event_type: 3 } } "
+ "event_callback_counter { count: 1 attributes { event_type: 4 } } ";
+
+ DrmFrameworkMetrics expectedMetricsProto;
+ ASSERT_TRUE(TextFormat::MergeFromString(expectedMetrics, &expectedMetricsProto));
+
+ std::string diffString;
+ MessageDifferencer differ;
+ differ.ReportDifferencesToString(&diffString);
+ ASSERT_TRUE(differ.Compare(expectedMetricsProto, metricsProto))
+ << diffString;
+}
+
+TEST_F(MediaDrmMetricsTest, TimeMetricsProtoSerialization) {
+ MediaDrmMetrics metrics;
+
+ for (status_t s : {OK, UNEXPECTED_NULL}) {
+ double time = 0;
+ for (int i = 0; i < 5; i++) {
+ time += 1.0;
+ metrics.mGetKeyRequestTimeUs.Record(time, s);
+ metrics.mProvideKeyResponseTimeUs.Record(time, s);
+ }
+ }
+
+ std::string serializedMetrics;
+ ASSERT_EQ(OK, metrics.GetSerializedMetrics(&serializedMetrics));
+
+ DrmFrameworkMetrics metricsProto;
+ ASSERT_TRUE(metricsProto.ParseFromString(serializedMetrics));
+
+ std::string expectedMetrics =
+ "get_key_request_timing { "
+ " min: 1 max: 5 mean: 3.5 variance: 1 operation_count: 5 "
+ " attributes { error_code: -0x7FFFFFF8 } "
+ "} "
+ "get_key_request_timing { "
+ " min: 1 max: 5 mean: 3.5 variance: 1 operation_count: 5 "
+ " attributes { error_code: 0 } "
+ "} "
+ "provide_key_response_timing { "
+ " min: 1 max: 5 mean: 3.5 variance: 1 operation_count: 5 "
+ " attributes { error_code: -0x7FFFFFF8 } "
+ "} "
+ "provide_key_response_timing { "
+ " min: 1 max: 5 mean: 3.5 variance: 1 operation_count: 5 "
+ " attributes { error_code: 0 } "
+ "} ";
+
+ DrmFrameworkMetrics expectedMetricsProto;
+ ASSERT_TRUE(TextFormat::MergeFromString(expectedMetrics, &expectedMetricsProto));
+
+ std::string diffString;
+ MessageDifferencer differ;
+ differ.ReportDifferencesToString(&diffString);
+ ASSERT_TRUE(differ.Compare(expectedMetricsProto, metricsProto))
+ << diffString;
+}
+
+TEST_F(MediaDrmMetricsTest, SessionLifetimeProtoSerialization) {
+ // Use the fake so the clock is predictable;
+ FakeMediaDrmMetrics metrics;
+
+ android::Vector<uint8_t> sessionId1;
+ sessionId1.push_back(1);
+ sessionId1.push_back(2);
+ android::Vector<uint8_t> sessionId2;
+ sessionId2.push_back(3);
+ sessionId2.push_back(4);
+
+ metrics.SetSessionStart(sessionId1);
+ metrics.SetSessionStart(sessionId2);
+ metrics.SetSessionEnd(sessionId2);
+ metrics.SetSessionEnd(sessionId1);
+
+ std::string serializedMetrics;
+ ASSERT_EQ(OK, metrics.GetSerializedMetrics(&serializedMetrics));
+
+ DrmFrameworkMetrics metricsProto;
+ ASSERT_TRUE(metricsProto.ParseFromString(serializedMetrics));
+
+ std::string expectedMetrics =
+ "session_lifetimes: { "
+ " key: '0102' "
+ " value { start_time_ms: 0 end_time_ms: 3 } "
+ "} "
+ "session_lifetimes: { "
+ " key: '0304' "
+ " value { start_time_ms: 1 end_time_ms: 2 } "
+ "} ";
+
+ DrmFrameworkMetrics expectedMetricsProto;
+ ASSERT_TRUE(TextFormat::MergeFromString(expectedMetrics, &expectedMetricsProto));
+
+ std::string diffString;
+ MessageDifferencer differ;
+ differ.ReportDifferencesToString(&diffString);
+ ASSERT_TRUE(differ.Compare(expectedMetricsProto, metricsProto))
+ << diffString;
+}
+
} // namespace android