Merge "libmediadrm: save IPC failure logs" into sc-dev (8b57c722) · Commits · e / os / android_frameworks_av

drm/libmediadrm/DrmHal.cpp

+6 −5

Original line number	Diff line number	Diff line
		@@ -345,10 +345,10 @@ std::vector<sp<IDrmFactory>> DrmHal::makeDrmFactories() {
		// must be in passthrough mode, load the default passthrough service
		auto passthrough = IDrmFactory::getService();
		if (passthrough != NULL) {
		ALOGI("makeDrmFactories: using default passthrough drm instance");
		DrmUtils::LOG2BI("makeDrmFactories: using default passthrough drm instance");
		factories.push_back(passthrough);
		} else {
		ALOGE("Failed to find any drm factories");
		DrmUtils::LOG2BE("Failed to find any drm factories");
		}
		}
		return factories;
		@@ -364,7 +364,7 @@ sp<IDrmPlugin> DrmHal::makeDrmPlugin(const sp<IDrmFactory>& factory,
		Return<void> hResult = factory->createPlugin(uuid, appPackageName.string(),
		[&](Status status, const sp<IDrmPlugin>& hPlugin) {
		if (status != Status::OK) {
		ALOGE("Failed to make drm plugin");
		DrmUtils::LOG2BE("Failed to make drm plugin: %d", status);
		return;
		}
		plugin = hPlugin;
		@@ -372,7 +372,7 @@ sp<IDrmPlugin> DrmHal::makeDrmPlugin(const sp<IDrmFactory>& factory,
		);

		if (!hResult.isOk()) {
		ALOGE("createPlugin remote call failed");
		DrmUtils::LOG2BE("createPlugin remote call failed");
		}

		return plugin;
		@@ -566,7 +566,8 @@ status_t DrmHal::createPlugin(const uint8_t uuid[16],
		Mutex::Autolock autoLock(mLock);

		for (ssize_t i = mFactories.size() - 1; i >= 0; i--) {
		if (mFactories[i]->isCryptoSchemeSupported(uuid)) {
		auto hResult = mFactories[i]->isCryptoSchemeSupported(uuid);
		if (hResult.isOk() && hResult) {
		auto plugin = makeDrmPlugin(mFactories[i], uuid, appPackageName);
		if (plugin != NULL) {
		mPlugin = plugin;

drm/libmediadrm/DrmUtils.cpp

+69 −3

Original line number	Diff line number	Diff line
		@@ -27,6 +27,8 @@
		#include <android/hardware/drm/1.2/IDrmFactory.h>
		#include <android/hardware/drm/1.3/ICryptoFactory.h>
		#include <android/hardware/drm/1.3/IDrmFactory.h>
		#include <android/hardware/drm/1.4/ICryptoFactory.h>
		#include <android/hardware/drm/1.4/IDrmFactory.h>
		#include <android/hidl/manager/1.2/IServiceManager.h>
		#include <hidl/HidlSupport.h>

		@@ -68,15 +70,15 @@ template <typename Hal, typename V>
		void MakeHidlFactories(const uint8_t uuid[16], V &factories) {
		sp<HServiceManager> serviceManager = HServiceManager::getService();
		if (serviceManager == nullptr) {
		ALOGE("Failed to get service manager");
		exit(-1);
		LOG2BE("Failed to get service manager");
		return;
		}

		serviceManager->listManifestByInterface(Hal::descriptor, [&](const hidl_vec<hidl_string> &registered) {
		for (const auto &instance : registered) {
		auto factory = Hal::getService(instance);
		if (factory != nullptr) {
		ALOGI("found %s %s", Hal::descriptor, instance.c_str());
		LOG2BI("found %s %s", Hal::descriptor, instance.c_str());
		if (!uuid \|\| factory->isCryptoSchemeSupported(uuid)) {
		factories.push_back(factory);
		}
		@@ -106,6 +108,7 @@ sp<::V1_0::IDrmPlugin> MakeDrmPlugin(const sp<::V1_0::IDrmFactory> &factory,
		factory->createPlugin(toHidlArray16(uuid), hidl_string(appPackageName),
		[&](::V1_0::Status status, const sp<::V1_0::IDrmPlugin> &hPlugin) {
		if (status != ::V1_0::Status::OK) {
		LOG2BE("MakeDrmPlugin failed: %d", status);
		return;
		}
		plugin = hPlugin;
		@@ -120,6 +123,7 @@ sp<::V1_0::ICryptoPlugin> MakeCryptoPlugin(const sp<::V1_0::ICryptoFactory> &fac
		factory->createPlugin(toHidlArray16(uuid), toHidlVec(initData, initDataSize),
		[&](::V1_0::Status status, const sp<::V1_0::ICryptoPlugin> &hPlugin) {
		if (status != ::V1_0::Status::OK) {
		LOG2BE("MakeCryptoPlugin failed: %d", status);
		return;
		}
		plugin = hPlugin;
		@@ -147,6 +151,7 @@ std::vector<sp<::V1_0::IDrmFactory>> MakeDrmFactories(const uint8_t uuid[16]) {
		MakeHidlFactories<::V1_1::IDrmFactory>(uuid, drmFactories);
		MakeHidlFactories<::V1_2::IDrmFactory>(uuid, drmFactories);
		MakeHidlFactories<::V1_3::IDrmFactory>(uuid, drmFactories);
		MakeHidlFactories<::V1_4::IDrmFactory>(uuid, drmFactories);
		return drmFactories;
		}

		@@ -165,6 +170,7 @@ std::vector<sp<::V1_0::ICryptoFactory>> MakeCryptoFactories(const uint8_t uuid[1
		MakeHidlFactories<::V1_1::ICryptoFactory>(uuid, cryptoFactories);
		MakeHidlFactories<::V1_2::ICryptoFactory>(uuid, cryptoFactories);
		MakeHidlFactories<::V1_3::ICryptoFactory>(uuid, cryptoFactories);
		MakeHidlFactories<::V1_4::ICryptoFactory>(uuid, cryptoFactories);
		return cryptoFactories;
		}

		@@ -265,5 +271,65 @@ status_t toStatusT_1_4(::V1_4::Status status) {
		return ERROR_DRM_UNKNOWN;
		}

		namespace {
		char logPriorityToChar(::V1_4::LogPriority priority) {
		char p = 'U';
		switch (priority) {
		case ::V1_4::LogPriority::VERBOSE: p = 'V'; break;
		case ::V1_4::LogPriority::DEBUG: p = 'D'; break;
		case ::V1_4::LogPriority::INFO: p = 'I'; break;
		case ::V1_4::LogPriority::WARN: p = 'W'; break;
		case ::V1_4::LogPriority::ERROR: p = 'E'; break;
		case ::V1_4::LogPriority::FATAL: p = 'F'; break;
		default: p = 'U'; break;
		}
		return p;
		}
		} // namespace

		std::string GetExceptionMessage(status_t err, const char *msg,
		const Vector<::V1_4::LogMessage> &logs) {
		String8 msg8;
		if (msg) {
		msg8 += msg;
		msg8 += ": ";
		}
		auto errStr = StrCryptoError(err);
		msg8 += errStr.c_str();

		for (auto log : logs) {
		time_t seconds = log.timeMs / 1000;
		int ms = log.timeMs % 1000;
		char buf[64] = {0};
		std::string timeStr = "00-00 00:00:00";
		if (strftime(buf, sizeof buf, "%m-%d %H:%M:%S", std::localtime(&seconds))) {
		timeStr = buf;
		}

		char p = logPriorityToChar(log.priority);
		msg8 += String8::format("\n%s.%03d %c %s", timeStr.c_str(), ms, p, log.message.c_str());
		}

		return msg8.c_str();
		}

		void LogBuffer::addLog(const ::V1_4::LogMessage &log) {
		std::unique_lock<std::mutex> lock(mMutex);
		mBuffer.push_back(log);
		while (mBuffer.size() > MAX_CAPACITY) {
		mBuffer.pop_front();
		}
		}

		Vector<::V1_4::LogMessage> LogBuffer::getLogs() {
		std::unique_lock<std::mutex> lock(mMutex);
		Vector<::V1_4::LogMessage> logs;
		for (auto log : mBuffer) {
		logs.push_back(log);
		}
		return logs;
		}

		LogBuffer gLogBuf;
		} // namespace DrmUtils
		} // namespace android

drm/libmediadrm/interface/mediadrm/DrmUtils.h

+79 −48

Original line number	Diff line number	Diff line
		@@ -27,7 +27,14 @@
		#include <utils/String8.h>
		#include <utils/StrongPointer.h>
		#include <utils/Vector.h>
		#include <algorithm>
		#include <chrono>
		#include <cstddef>
		#include <cstdint>
		#include <ctime>
		#include <deque>
		#include <iterator>
		#include <mutex>
		#include <vector>


		@@ -42,6 +49,53 @@ struct IDrm;

		namespace DrmUtils {

		// Log APIs
		class LogBuffer {
		public:
		static const int MAX_CAPACITY = 100;
		void addLog(const ::V1_4::LogMessage &log);
		Vector<::V1_4::LogMessage> getLogs();

		private:
		std::deque<::V1_4::LogMessage> mBuffer;
		std::mutex mMutex;
		};

		extern LogBuffer gLogBuf;

		static inline int formatBuffer(char buf, size_t size, const char msg) {
		return snprintf(buf, size, "%s", msg);
		}

		template <typename First, typename... Args>
		static inline int formatBuffer(char buf, size_t size, const char fmt, First first, Args... args) {
		return snprintf(buf, size, fmt, first, args...);
		}

		template <typename... Args>
		void LogToBuffer(android_LogPriority level, const char *fmt, Args... args) {
		const int LOG_BUF_SIZE = 256;
		char buf[LOG_BUF_SIZE];
		int len = formatBuffer(buf, LOG_BUF_SIZE, fmt, args...);
		if (len <= 0) {
		return;
		}
		__android_log_write(level, LOG_TAG, buf);
		if (level >= ANDROID_LOG_INFO) {
		int64_t epochTimeMs =
		std::chrono::system_clock::now().time_since_epoch() / std::chrono::milliseconds(1);
		gLogBuf.addLog({epochTimeMs, static_cast<::V1_4::LogPriority>(level), buf});
		}
		}

		#ifndef LOG2BE
		#define LOG2BE(...) LogToBuffer(ANDROID_LOG_ERROR, __VA_ARGS__)
		#define LOG2BW(...) LogToBuffer(ANDROID_LOG_WARN, __VA_ARGS__)
		#define LOG2BI(...) LogToBuffer(ANDROID_LOG_INFO, __VA_ARGS__)
		#define LOG2BD(...) LogToBuffer(ANDROID_LOG_DEBUG, __VA_ARGS__)
		#define LOG2BV(...) LogToBuffer(ANDROID_LOG_VERBOSE, __VA_ARGS__)
		#endif

		bool UseDrmService();

		sp<IDrm> MakeDrm(status_t *pstatus = nullptr);
		@@ -119,11 +173,14 @@ inline status_t toStatusT(const android::hardware::Return<T> &status) {
		template<typename T, typename U>
		status_t GetLogMessages(const sp<U> &obj, Vector<::V1_4::LogMessage> &logs) {
		sp<T> plugin = T::castFrom(obj);
		if (plugin == NULL) {
		return ERROR_UNSUPPORTED;
		if (obj == NULL) {
		LOG2BW("%s obj is null", U::descriptor);
		} else if (plugin == NULL) {
		LOG2BW("Cannot cast %s obj to %s plugin", U::descriptor, T::descriptor);
		}

		::V1_4::Status err{};
		std::vector<::V1_4::LogMessage> pluginLogs;
		::V1_4::IDrmPlugin::getLogMessages_cb cb = [&](
		::V1_4::Status status,
		hidl_vec<::V1_4::LogMessage> hLogs) {
		@@ -131,62 +188,36 @@ status_t GetLogMessages(const sp<U> &obj, Vector<::V1_4::LogMessage> &logs) {
		err = status;
		return;
		}
		logs.appendArray(hLogs.data(), hLogs.size());
		pluginLogs.assign(hLogs.data(), hLogs.data() + hLogs.size());
		};

		Return<void> hResult = plugin->getLogMessages(cb);
		if (!hResult.isOk()) {
		return DEAD_OBJECT;
		Return<void> hResult;
		if (plugin != NULL) {
		hResult = plugin->getLogMessages(cb);
		}
		return toStatusT(err);
		if (!hResult.isOk()) {
		LOG2BW("%s::getLogMessages remote call failed", T::descriptor);
		}

		namespace {
		static inline char logPriorityToChar(::V1_4::LogPriority priority) {
		char p = 'U';
		switch (priority) {
		case ::V1_4::LogPriority::VERBOSE: p = 'V'; break;
		case ::V1_4::LogPriority::DEBUG: p = 'D'; break;
		case ::V1_4::LogPriority::INFO: p = 'I'; break;
		case ::V1_4::LogPriority::WARN: p = 'W'; break;
		case ::V1_4::LogPriority::ERROR: p = 'E'; break;
		case ::V1_4::LogPriority::FATAL: p = 'F'; break;
		default: p = 'U'; break;
		}
		return p;
		}
		auto allLogs(gLogBuf.getLogs());
		std::copy(pluginLogs.begin(), pluginLogs.end(), std::back_inserter(allLogs));
		std::sort(allLogs.begin(), allLogs.end(),
		[](const ::V1_4::LogMessage &a, const ::V1_4::LogMessage &b) {
		return a.timeMs < b.timeMs;
		});

		logs.appendVector(allLogs);
		return OK;
		}

		std::string GetExceptionMessage(status_t err, const char *msg,
		const Vector<::V1_4::LogMessage> &logs);

		template<typename T>
		std::string GetExceptionMessage(status_t err, const char *msg, const sp<T> &iface) {
		String8 msg8;
		if (msg) {
		msg8 += msg;
		msg8 += ": ";
		}
		auto errStr = StrCryptoError(err);
		msg8 += errStr.c_str();

		Vector<::V1_4::LogMessage> logs;
		if (iface->getLogMessages(logs) != NO_ERROR) {
		return msg8.c_str();
		}

		for (auto log: logs) {
		time_t seconds = log.timeMs / 1000;
		int ms = log.timeMs % 1000;
		char buf[64] = {0};
		std::string timeStr = "00-00 00:00:00";
		if (strftime(buf, sizeof buf, "%m-%d %H:%M:%S", std::localtime(&seconds))) {
		timeStr = buf;
		}

		char p = logPriorityToChar(log.priority);
		msg8 += String8::format("\n%s.%03d %c %s",
		timeStr.c_str(), ms, p, log.message.c_str());
		}

		return msg8.c_str();
		iface->getLogMessages(logs);
		return GetExceptionMessage(err, msg, logs);
		}

		} // namespace DrmUtils