Add logging support for FW metrics (fb679e38) · Commits · e / os / android_frameworks_av

drm/libmediadrm/Android.bp

+65 −7

Original line number	Diff line number	Diff line
		@@ -15,25 +15,20 @@ cc_library {
		"IDrm.cpp",
		"IDrmClient.cpp",
		"IMediaDrmService.cpp",
		"PluginMetricsReporting.cpp",
		"SharedLibrary.cpp",
		"DrmHal.cpp",
		"DrmMetrics.cpp",
		"CryptoHal.cpp",
		"protos/plugin_metrics.proto",
		],

		proto: {
		type: "lite",
		},

		shared_libs: [
		"libbinder",
		"libcutils",
		"libdl",
		"liblog",
		"libmediadrmmetrics_lite",
		"libmediametrics",
		"libmediautils",
		"libprotobuf-cpp-lite",
		"libstagefright_foundation",
		"libutils",
		"android.hardware.drm@1.0",
		@@ -48,3 +43,66 @@ cc_library {
		"-Wall",
		],
		}

		// This is the version of the drm metrics configured for protobuf lite.
		cc_library_shared {
		name: "libmediadrmmetrics_lite",
		srcs: [
		"DrmMetrics.cpp",
		"PluginMetricsReporting.cpp",
		"protos/metrics.proto",
		],

		proto: {
		export_proto_headers: true,
		type: "lite",
		},
		shared_libs: [
		"android.hardware.drm@1.0",
		"android.hardware.drm@1.1",
		"libbase",
		"libbinder",
		"liblog",
		"libmediametrics",
		"libprotobuf-cpp-lite",
		"libutils",
		],
		cflags: [
		// Suppress unused parameter and no error options. These cause problems
		// with the when using the map type in a proto definition.
		"-Wno-unused-parameter",
		"-Wno-error",
		],
		}

		// This is the version of the drm metrics library configured for full protobuf.
		cc_library_shared {
		name: "libmediadrmmetrics_full",
		srcs: [
		"DrmMetrics.cpp",
		"PluginMetricsReporting.cpp",
		"protos/metrics.proto",
		],

		proto: {
		export_proto_headers: true,
		type: "full",
		},
		shared_libs: [
		"android.hardware.drm@1.0",
		"android.hardware.drm@1.1",
		"libbase",
		"libbinder",
		"liblog",
		"libmediametrics",
		"libprotobuf-cpp-full",
		"libutils",
		],
		cflags: [
		// Suppress unused parameter and no error options. These cause problems
		// when using the map type in a proto definition.
		"-Wno-unused-parameter",
		"-Wno-error",
		],
		}

drm/libmediadrm/DrmHal.cpp

+51 −5

Original line number	Diff line number	Diff line
		@@ -16,6 +16,8 @@

		//#define LOG_NDEBUG 0
		#define LOG_TAG "DrmHal"
		#include <iomanip>

		#include <utils/Log.h>

		#include <binder/IPCThreadState.h>
		@@ -98,6 +100,15 @@ static hidl_string toHidlString(const String8& string) {
		return hidl_string(string.string());
		}

		std::string ToHexString(const std::string& str) {
		std::ostringstream out;
		out << std::hex << std::setfill('0');
		for (size_t i = 0; i < str.size(); i++) {
		out << std::setw(2) << (int)(str[i]);
		}
		return out.str();
		}

		static DrmPlugin::SecurityLevel toSecurityLevel(SecurityLevel level) {
		switch(level) {
		case SecurityLevel::SW_SECURE_CRYPTO:
		@@ -309,6 +320,7 @@ Vector<sp<IDrmFactory>> DrmHal::makeDrmFactories() {

		sp<IDrmPlugin> DrmHal::makeDrmPlugin(const sp<IDrmFactory>& factory,
		const uint8_t uuid[16], const String8& appPackageName) {
		mMetrics.SetAppPackageName(appPackageName);

		sp<IDrmPlugin> plugin;
		Return<void> hResult = factory->createPlugin(uuid, appPackageName.string(),
		@@ -504,7 +516,8 @@ status_t DrmHal::destroyPlugin() {
		INIT_CHECK();

		closeOpenSessions();
		reportMetrics();
		reportPluginMetrics();
		reportFrameworkMetrics();
		setListener(NULL);
		mInitCheck = NO_INIT;

		@@ -620,7 +633,7 @@ status_t DrmHal::closeSession(Vector<uint8_t> const &sessionId) {
		status_t response = toStatusT(status);
		mMetrics.SetSessionEnd(sessionId);
		mMetrics.mCloseSessionCounter.Increment(response);
		reportMetrics();
		reportPluginMetrics();
		return response;
		}
		mMetrics.mCloseSessionCounter.Increment(DEAD_OBJECT);
		@@ -634,7 +647,7 @@ status_t DrmHal::getKeyRequest(Vector<uint8_t> const &sessionId,
		String8 &defaultUrl, DrmPlugin::KeyRequestType *keyRequestType) {
		Mutex::Autolock autoLock(mLock);
		INIT_CHECK();
		EventTimer<status_t> keyRequestTimer(&mMetrics.mGetKeyRequestTiming);
		EventTimer<status_t> keyRequestTimer(&mMetrics.mGetKeyRequestTimeUs);

		DrmSessionManager::Instance()->useSession(sessionId);

		@@ -729,7 +742,7 @@ status_t DrmHal::getKeyRequest(Vector<uint8_t> const &sessionId,
		status_t DrmHal::provideKeyResponse(Vector<uint8_t> const &sessionId,
		Vector<uint8_t> const &response, Vector<uint8_t> &keySetId) {
		Mutex::Autolock autoLock(mLock);
		EventTimer<status_t> keyResponseTimer(&mMetrics.mProvideKeyResponseTiming);
		EventTimer<status_t> keyResponseTimer(&mMetrics.mProvideKeyResponseTimeUs);

		INIT_CHECK();

		@@ -1277,8 +1290,41 @@ void DrmHal::writeByteArray(Parcel &obj, hidl_vec<uint8_t> const &vec)
		}
		}

		void DrmHal::reportFrameworkMetrics() const
		{
		MediaAnalyticsItem item("mediadrm");
		item.generateSessionID();
		item.setPkgName(mMetrics.GetAppPackageName().c_str());
		String8 vendor;
		String8 description;
		status_t result = getPropertyStringInternal(String8("vendor"), vendor);
		if (result != OK) {
		ALOGE("Failed to get vendor from drm plugin. %d", result);
		} else {
		item.setCString("vendor", vendor.c_str());
		}
		result = getPropertyStringInternal(String8("description"), description);
		if (result != OK) {
		ALOGE("Failed to get description from drm plugin. %d", result);
		} else {
		item.setCString("description", description.c_str());
		}

		std::string serializedMetrics;
		result = mMetrics.GetSerializedMetrics(&serializedMetrics);
		if (result != OK) {
		ALOGE("Failed to serialize Framework metrics: %d", result);
		}
		serializedMetrics = ToHexString(serializedMetrics);
		if (!serializedMetrics.empty()) {
		item.setCString("serialized_metrics", serializedMetrics.c_str());
		}
		if (!item.selfrecord()) {
		ALOGE("Failed to self record framework metrics.");
		}
		}

		void DrmHal::reportMetrics() const
		void DrmHal::reportPluginMetrics() const
		{
		Vector<uint8_t> metrics;
		String8 vendor;

drm/libmediadrm/DrmMetrics.cpp

+138 −24

Original line number	Diff line number	Diff line
		@@ -13,15 +13,22 @@
		* See the License for the specific language governing permissions and
		* limitations under the License.
		*/

		#define LOG_TAG "DrmMetrics"
		#include <iomanip>
		#include <utility>

		#include <android-base/macros.h>
		#include <media/DrmMetrics.h>
		#include <media/stagefright/foundation/base64.h>
		#include <sys/time.h>
		#include <utils/Log.h>
		#include <utils/Timers.h>

		#include "protos/metrics.pb.h"

		using ::android::String16;
		using ::android::String8;
		using ::android::drm_metrics::DrmFrameworkMetrics;
		using ::android::hardware::drm::V1_0::EventType;
		using ::android::hardware::drm::V1_0::KeyStatusType;
		using ::android::os::PersistableBundle;
		@@ -130,8 +137,7 @@ void ExportEventMetric(const android::EventMetric<T> &event,
		}

		void ExportSessionLifespans(
		const std::map<android::String16, std::pair<int64_t, int64_t>>
		&mSessionLifespans,
		const std::map<std::string, std::pair<int64_t, int64_t>> &mSessionLifespans,
		PersistableBundle *metrics) {
		if (!metrics) {
		ALOGE("metrics was unexpectedly null.");
		@@ -146,9 +152,9 @@ void ExportSessionLifespans(
		PersistableBundle endTimesBundle;
		for (auto it = mSessionLifespans.begin(); it != mSessionLifespans.end();
		it++) {
		startTimesBundle.putLong(android::String16(it->first),
		it->second.first);
		endTimesBundle.putLong(android::String16(it->first), it->second.second);
		String16 key(it->first.c_str(), it->first.size());
		startTimesBundle.putLong(key, it->second.first);
		endTimesBundle.putLong(key, it->second.second);
		}
		metrics->putPersistableBundle(
		android::String16("drm.mediadrm.session_start_times_ms"),
		@@ -157,18 +163,13 @@ void ExportSessionLifespans(
		android::String16("drm.mediadrm.session_end_times_ms"), endTimesBundle);
		}

		android::String8 ToHexString(const android::Vector<uint8_t> &sessionId) {
		android::String8 result;
		std::string ToHexString(const android::Vector<uint8_t> &sessionId) {
		std::ostringstream out;
		out << std::hex << std::setfill('0');
		for (size_t i = 0; i < sessionId.size(); i++) {
		result.appendFormat("%02x", sessionId[i]);
		}
		return result;
		out << std::setw(2) << (int)(sessionId[i]);
		}

		int64_t getCurrentTimeMs() {
		struct timeval tv;
		gettimeofday(&tv, NULL);
		return ((int64_t)tv.tv_sec * 1000) + ((int64_t)tv.tv_usec / 1000);
		return out.str();
		}

		} // namespace
		@@ -178,8 +179,8 @@ namespace android {
		MediaDrmMetrics::MediaDrmMetrics()
		: mOpenSessionCounter("drm.mediadrm.open_session", "status"),
		mCloseSessionCounter("drm.mediadrm.close_session", "status"),
		mGetKeyRequestTiming("drm.mediadrm.get_key_request", "status"),
		mProvideKeyResponseTiming("drm.mediadrm.provide_key_response", "status"),
		mGetKeyRequestTimeUs("drm.mediadrm.get_key_request", "status"),
		mProvideKeyResponseTimeUs("drm.mediadrm.provide_key_response", "status"),
		mGetProvisionRequestCounter("drm.mediadrm.get_provision_request",
		"status"),
		mProvideProvisionResponseCounter(
		@@ -192,14 +193,14 @@ MediaDrmMetrics::MediaDrmMetrics()

		void MediaDrmMetrics::SetSessionStart(
		const android::Vector<uint8_t> &sessionId) {
		String16 sessionIdHex = String16(ToHexString(sessionId));
		std::string sessionIdHex = ToHexString(sessionId);
		mSessionLifespans[sessionIdHex] =
		std::make_pair(getCurrentTimeMs(), (int64_t)0);
		std::make_pair(GetCurrentTimeMs(), (int64_t)0);
		}

		void MediaDrmMetrics::SetSessionEnd(const android::Vector<uint8_t> &sessionId) {
		String16 sessionIdHex = String16(ToHexString(sessionId));
		int64_t endTimeMs = getCurrentTimeMs();
		std::string sessionIdHex = ToHexString(sessionId);
		int64_t endTimeMs = GetCurrentTimeMs();
		if (mSessionLifespans.find(sessionIdHex) != mSessionLifespans.end()) {
		mSessionLifespans[sessionIdHex] =
		std::make_pair(mSessionLifespans[sessionIdHex].first, endTimeMs);
		@@ -215,8 +216,8 @@ void MediaDrmMetrics::Export(PersistableBundle *metrics) {
		}
		ExportCounterMetric(mOpenSessionCounter, metrics);
		ExportCounterMetric(mCloseSessionCounter, metrics);
		ExportEventMetric(mGetKeyRequestTiming, metrics);
		ExportEventMetric(mProvideKeyResponseTiming, metrics);
		ExportEventMetric(mGetKeyRequestTimeUs, metrics);
		ExportEventMetric(mProvideKeyResponseTimeUs, metrics);
		ExportCounterMetric(mGetProvisionRequestCounter, metrics);
		ExportCounterMetric(mProvideProvisionResponseCounter, metrics);
		ExportCounterMetricWithAttributeNames(mKeyStatusChangeCounter, metrics);
		@@ -225,4 +226,117 @@ void MediaDrmMetrics::Export(PersistableBundle *metrics) {
		ExportSessionLifespans(mSessionLifespans, metrics);
		}

		status_t MediaDrmMetrics::GetSerializedMetrics(std::string *serializedMetrics) {

		if (!serializedMetrics) {
		ALOGE("serializedMetrics was unexpectedly null.");
		return UNEXPECTED_NULL;
		}

		DrmFrameworkMetrics metrics;

		mOpenSessionCounter.ExportValues(
		[&](const android::status_t status, const int64_t value) {
		DrmFrameworkMetrics::Counter *counter =
		metrics.add_open_session_counter();
		counter->set_count(value);
		counter->mutable_attributes()->set_error_code(status);
		});

		mCloseSessionCounter.ExportValues(
		[&](const android::status_t status, const int64_t value) {
		DrmFrameworkMetrics::Counter *counter =
		metrics.add_close_session_counter();
		counter->set_count(value);
		counter->mutable_attributes()->set_error_code(status);
		});

		mGetProvisionRequestCounter.ExportValues(
		[&](const android::status_t status, const int64_t value) {
		DrmFrameworkMetrics::Counter *counter =
		metrics.add_get_provisioning_request_counter();
		counter->set_count(value);
		counter->mutable_attributes()->set_error_code(status);
		});

		mProvideProvisionResponseCounter.ExportValues(
		[&](const android::status_t status, const int64_t value) {
		DrmFrameworkMetrics::Counter *counter =
		metrics.add_provide_provisioning_response_counter();
		counter->set_count(value);
		counter->mutable_attributes()->set_error_code(status);
		});

		mKeyStatusChangeCounter.ExportValues(
		[&](const KeyStatusType key_status_type, const int64_t value) {
		DrmFrameworkMetrics::Counter *counter =
		metrics.add_key_status_change_counter();
		counter->set_count(value);
		counter->mutable_attributes()->set_key_status_type(
		(uint32_t)key_status_type);
		});

		mEventCounter.ExportValues(
		[&](const EventType event_type, const int64_t value) {
		DrmFrameworkMetrics::Counter *counter =
		metrics.add_event_callback_counter();
		counter->set_count(value);
		counter->mutable_attributes()->set_event_type((uint32_t)event_type);
		});

		mGetDeviceUniqueIdCounter.ExportValues(
		[&](const status_t status, const int64_t value) {
		DrmFrameworkMetrics::Counter *counter =
		metrics.add_get_device_unique_id_counter();
		counter->set_count(value);
		counter->mutable_attributes()->set_error_code(status);
		});

		mGetKeyRequestTimeUs.ExportValues(
		[&](const status_t status, const EventStatistics &stats) {
		DrmFrameworkMetrics::DistributionMetric *metric =
		metrics.add_get_key_request_time_us();
		metric->set_min(stats.min);
		metric->set_max(stats.max);
		metric->set_mean(stats.mean);
		metric->set_operation_count(stats.count);
		metric->set_variance(stats.sum_squared_deviation / stats.count);
		metric->mutable_attributes()->set_error_code(status);
		});

		mProvideKeyResponseTimeUs.ExportValues(
		[&](const status_t status, const EventStatistics &stats) {
		DrmFrameworkMetrics::DistributionMetric *metric =
		metrics.add_provide_key_response_time_us();
		metric->set_min(stats.min);
		metric->set_max(stats.max);
		metric->set_mean(stats.mean);
		metric->set_operation_count(stats.count);
		metric->set_variance(stats.sum_squared_deviation / stats.count);
		metric->mutable_attributes()->set_error_code(status);
		});

		for (const auto &sessionLifespan : mSessionLifespans) {
		auto *map = metrics.mutable_session_lifetimes();

		(*map)[sessionLifespan.first].set_start_time_ms(
		sessionLifespan.second.first);
		(*map)[sessionLifespan.first].set_end_time_ms(
		sessionLifespan.second.second);
		}

		if (!metrics.SerializeToString(serializedMetrics)) {
		ALOGE("Failed to serialize metrics.");
		return UNKNOWN_ERROR;
		}

		return OK;
		}

		int64_t MediaDrmMetrics::GetCurrentTimeMs() {
		struct timeval tv;
		gettimeofday(&tv, NULL);
		return ((int64_t)tv.tv_sec * 1000) + ((int64_t)tv.tv_usec / 1000);
		}

		} // namespace android

drm/libmediadrm/PluginMetricsReporting.cpp

+1 −1

Original line number	Diff line number	Diff line
		@@ -23,7 +23,7 @@

		#include <media/MediaAnalyticsItem.h>

		#include "protos/plugin_metrics.pb.h"
		#include "protos/metrics.pb.h"

		namespace android {

drm/libmediadrm/protos/plugin_metrics.proto→drm/libmediadrm/protos/metrics.proto

+134 −0

Original line number	Diff line number	Diff line
		@@ -18,9 +18,6 @@ syntax = "proto2";

		package android.drm_metrics;

		// need this if we are using libprotobuf-cpp-2.3.0-lite
		option optimize_for = LITE_RUNTIME;

		// The MetricsGroup is a collection of metric name/value pair instances
		// that can be serialized and provided to a caller.
		message MetricsGroup {
		@@ -48,3 +45,90 @@ message MetricsGroup {
		// Name of the application package associated with the metrics.
		optional string app_package_name = 3;
		}

		// This message contains the specific metrics captured by DrmMetrics. It is
		// used for serializing and logging metrics.
		// next id: 11.
		message DrmFrameworkMetrics {
		// TODO: Consider using extensions.

		// Attributes are associated with a recorded value. E.g. A counter may
		// represent a count of an operation returning a specific error code. The
		// error code will be an attribute.
		message Attributes {
		// Reserved for compatibility with logging proto.
		reserved 2 to 13;

		// A general purpose error code where 0 means OK.
		optional int32 error_code = 1;

		// Defined at ::android::hardware::drm::V1_0::KeyStatusType;
		optional uint32 key_status_type = 14;

		// Defined at ::android::hardware::drm::V1_0::EventType;
		optional uint32 event_type = 15;
		}

		// The Counter message is used to store a count value with an associated
		// Attribute.
		message Counter {
		optional int64 count = 1;
		// Represents the attributes associated with this counter instance.
		optional Attributes attributes = 2;
		}

		// The DistributionMetric is meant to capture the moments of a normally
		// distributed (or approximately normal) value.
		message DistributionMetric {
		optional double min = 1;
		optional double max = 2;
		optional double mean = 3;
		optional double variance = 4;
		optional double operation_count = 5;

		// Represents the attributes assocated with this distribution metric
		// instance.
		optional Attributes attributes = 6;
		}

		message SessionLifetime {
		// Start time of the session in milliseconds since epoch.
		optional int64 start_time_ms = 1;
		// End time of the session in milliseconds since epoch.
		optional int64 end_time_ms = 2;
		}

		// The count of open session operations. Each instance has a specific error
		// code associated with it.
		repeated Counter open_session_counter = 1;

		// The count of close session operations. Each instance has a specific error
		// code associated with it.
		repeated Counter close_session_counter = 2;

		// Count and execution time of getKeyRequest calls.
		repeated DistributionMetric get_key_request_time_us = 3;

		// Count and execution time of provideKeyResponse calls.
		repeated DistributionMetric provide_key_response_time_us = 4;

		// Count of getProvisionRequest calls.
		repeated Counter get_provisioning_request_counter = 5;

		// Count of provideProvisionResponse calls.
		repeated Counter provide_provisioning_response_counter = 6;

		// Count of key status events broken out by status type.
		repeated Counter key_status_change_counter = 7;

		// Count of events broken out by event type
		repeated Counter event_callback_counter = 8;

		// Count getPropertyByteArray calls to retrieve the device unique id.
		repeated Counter get_device_unique_id_counter = 9;

		// Session ids to lifetime (start and end time) map.
		// Session ids are strings of hex-encoded byte arrays.
		map<string, SessionLifetime> session_lifetimes = 10;
		}