Merge "Add support for multi train logging" (763cb8f9) · Commits · e / os / android_frameworks_base

apex/statsd/aidl/android/os/IStatsd.aidl

+0 −6

Original line number	Diff line number	Diff line
		@@ -221,12 +221,6 @@ interface IStatsd {
		*/
		const int FLAG_REQUIRE_LOW_LATENCY_MONITOR = 0x04;

		/**
		* Logs an event for watchdog rollbacks.
		*/
		oneway void sendWatchdogRollbackOccurredAtom(in int rollbackType, in String packageName,
		in long packageVersionCode, in int rollbackReason, in String failingPackageName);

		/**
		* Returns the most recently registered experiment IDs.
		*/

apex/statsd/framework/java/android/util/StatsLog.java

+2 −43

Original line number	Diff line number	Diff line
		@@ -171,51 +171,10 @@ public final class StatsLog {
		state,
		proto.getBytes(),
		0,
		0);
		return true;
		}

		/**
		* Logs an event for watchdog rollbacks.
		*
		* @param rollbackType state of the rollback.
		* @param packageName package name being rolled back.
		* @param packageVersionCode version of the package being rolled back.
		* @param rollbackReason reason the package is being rolled back.
		* @param failingPackageName the package name causing the failure.
		*
		* @return True if the log request was sent to statsd.
		*
		* @hide
		*/
		@RequiresPermission(allOf = {DUMP, PACKAGE_USAGE_STATS})
		public static boolean logWatchdogRollbackOccurred(int rollbackType, String packageName,
		long packageVersionCode, int rollbackReason, String failingPackageName) {
		synchronized (sLogLock) {
		try {
		IStatsd service = getIStatsdLocked();
		if (service == null) {
		if (DEBUG) {
		Slog.d(TAG, "Failed to find statsd when logging event");
		}
		return false;
		}

		service.sendWatchdogRollbackOccurredAtom(rollbackType, packageName,
		packageVersionCode, rollbackReason, failingPackageName);
		0,
		false);
		return true;
		} catch (RemoteException e) {
		sService = null;
		if (DEBUG) {
		Slog.d(TAG,
		"Failed to connect to StatsCompanionService when logging "
		+ "WatchdogRollbackOccurred");
		}
		return false;
		}
		}
		}


		private static IStatsd getIStatsdLocked() throws RemoteException {
		if (sService != null) {

cmds/statsd/src/StatsLogProcessor.cpp

+131 −44

Original line number	Diff line number	Diff line
		@@ -196,17 +196,27 @@ void StatsLogProcessor::onBinaryPushStateChangedEventLocked(LogEvent* event) {
		!checkPermissionForIds(kPermissionUsage, pid, uid)) {
		return;
		}
		status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR, err4 = NO_ERROR;
		string trainName = string(event->GetString(1 /train name field id/, &err));
		int64_t trainVersionCode = event->GetLong(2 /train version field id/, &err2);
		int32_t state = int32_t(event->GetLong(6 /state field id/, &err3));
		// The Get* functions don't modify the status on success, they only write in
		// failure statuses, so we can use one status variable for all calls then
		// check if it is no longer NO_ERROR.
		status_t err = NO_ERROR;
		InstallTrainInfo trainInfo;
		trainInfo.trainName = string(event->GetString(1 /train name field id/, &err));
		trainInfo.trainVersionCode = event->GetLong(2 /train version field id/, &err);
		trainInfo.requiresStaging = event->GetBool(3 /requires staging field id/, &err);
		trainInfo.rollbackEnabled = event->GetBool(4 /rollback enabled field id/, &err);
		trainInfo.requiresLowLatencyMonitor =
		event->GetBool(5 /requires low latency monitor field id/, &err);
		trainInfo.status = int32_t(event->GetLong(6 /state field id/, &err));
		#ifdef NEW_ENCODING_SCHEME
		std::vector<uint8_t> trainExperimentIdBytes =
		event->GetStorage(7 /experiment ids field id/, &err4);
		event->GetStorage(7 /experiment ids field id/, &err);
		#else
		string trainExperimentIdString = event->GetString(7 /experiment ids field id/, &err4);
		string trainExperimentIdString = event->GetString(7 /experiment ids field id/, &err);
		#endif
		if (err != NO_ERROR \|\| err2 != NO_ERROR \|\| err3 != NO_ERROR \|\| err4 != NO_ERROR) {
		bool is_rollback = event->GetBool(10 /is rollback field id/, &err);

		if (err != NO_ERROR) {
		ALOGE("Failed to parse fields in binary push state changed log event");
		return;
		}
		@@ -220,83 +230,154 @@ void StatsLogProcessor::onBinaryPushStateChangedEventLocked(LogEvent* event) {
		ALOGE("Failed to parse experimentids in binary push state changed.");
		return;
		}
		vector<int64_t> experimentIdVector = {trainExperimentIds.experiment_id().begin(),
		trainInfo.experimentIds = {trainExperimentIds.experiment_id().begin(),
		trainExperimentIds.experiment_id().end()};

		// Update the train info on disk and get any data the logevent is missing.
		getAndUpdateTrainInfoOnDisk(
		state, &trainVersionCode, &trainName, &experimentIdVector);
		getAndUpdateTrainInfoOnDisk(is_rollback, &trainInfo);

		std::vector<uint8_t> trainExperimentIdProto;
		writeExperimentIdsToProto(experimentIdVector, &trainExperimentIdProto);
		writeExperimentIdsToProto(trainInfo.experimentIds, &trainExperimentIdProto);
		int32_t userId = multiuser_get_user_id(uid);

		event->updateValue(1 /train name field id/, trainName, STRING);
		event->updateValue(2 /train version field id/, trainVersionCode, LONG);
		event->updateValue(2 /train version field id/, trainInfo.trainVersionCode, LONG);
		#ifdef NEW_ENCODING_SCHEME
		event->updateValue(7 /experiment ids field id/, trainExperimentIdProto, STORAGE);
		#else
		event->updateValue(7 /experiment ids field id/, trainExperimentIdProto, STRING);
		#endif
		event->updateValue(8 /user id field id/, userId, INT);

		if (is_rollback) {
		int bit = trainInfo.requiresStaging ? 1 : 0;
		event->updateValue(3 /requires staging field id/, bit, INT);
		bit = trainInfo.rollbackEnabled ? 1 : 0;
		event->updateValue(4 /rollback enabled field id/, bit, INT);
		bit = trainInfo.requiresLowLatencyMonitor ? 1 : 0;
		event->updateValue(5 /requires low latency monitor field id/, bit, INT);
		}
		}

		void StatsLogProcessor::getAndUpdateTrainInfoOnDisk(int32_t state,
		int64_t* trainVersionCode,
		string* trainName,
		std::vector<int64_t>* experimentIds) {
		void StatsLogProcessor::getAndUpdateTrainInfoOnDisk(bool is_rollback,
		InstallTrainInfo* trainInfo) {
		// If the train name is empty, we don't know which train to attribute the
		// event to, so return early.
		if (trainInfo->trainName.empty()) {
		return;
		}
		bool readTrainInfoSuccess = false;
		InstallTrainInfo trainInfoOnDisk;
		readTrainInfoSuccess = StorageManager::readTrainInfo(trainInfoOnDisk);
		readTrainInfoSuccess = StorageManager::readTrainInfo(trainInfo->trainName, trainInfoOnDisk);

		bool resetExperimentIds = false;
		if (readTrainInfoSuccess) {
		// Keep the old train version if we received an empty version.
		if (*trainVersionCode == -1) {
		*trainVersionCode = trainInfoOnDisk.trainVersionCode;
		} else if (*trainVersionCode != trainInfoOnDisk.trainVersionCode) {
		if (trainInfo->trainVersionCode == -1) {
		trainInfo->trainVersionCode = trainInfoOnDisk.trainVersionCode;
		} else if (trainInfo->trainVersionCode != trainInfoOnDisk.trainVersionCode) {
		// Reset experiment ids if we receive a new non-empty train version.
		resetExperimentIds = true;
		}

		// Keep the old train name if we received an empty train name.
		if (trainName->size() == 0) {
		*trainName = trainInfoOnDisk.trainName;
		} else if (*trainName != trainInfoOnDisk.trainName) {
		// Reset experiment ids if we received a new valid train name.
		resetExperimentIds = true;
		}

		// Reset if we received a different experiment id.
		if (!experimentIds->empty() &&
		if (!trainInfo->experimentIds.empty() &&
		(trainInfoOnDisk.experimentIds.empty() \|\|
		experimentIds->at(0) != trainInfoOnDisk.experimentIds[0])) {
		trainInfo->experimentIds.at(0) != trainInfoOnDisk.experimentIds[0])) {
		resetExperimentIds = true;
		}
		}

		// Find the right experiment IDs
		if (!resetExperimentIds && readTrainInfoSuccess) {
		*experimentIds = trainInfoOnDisk.experimentIds;
		if ((!resetExperimentIds \|\| is_rollback) && readTrainInfoSuccess) {
		trainInfo->experimentIds = trainInfoOnDisk.experimentIds;
		}

		if (!experimentIds->empty()) {
		int64_t firstId = experimentIds->at(0);
		switch (state) {
		if (!trainInfo->experimentIds.empty()) {
		int64_t firstId = trainInfo->experimentIds.at(0);
		switch (trainInfo->status) {
		case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALL_SUCCESS:
		experimentIds->push_back(firstId + 1);
		trainInfo->experimentIds.push_back(firstId + 1);
		break;
		case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_INITIATED:
		experimentIds->push_back(firstId + 2);
		trainInfo->experimentIds.push_back(firstId + 2);
		break;
		case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_SUCCESS:
		experimentIds->push_back(firstId + 3);
		trainInfo->experimentIds.push_back(firstId + 3);
		break;
		}
		}

		StorageManager::writeTrainInfo(trainVersionCode, trainName, state, *experimentIds);
		if (is_rollback) {
		trainInfo->requiresStaging = trainInfoOnDisk.requiresStaging;
		trainInfo->rollbackEnabled = trainInfoOnDisk.rollbackEnabled;
		trainInfo->requiresLowLatencyMonitor = trainInfoOnDisk.requiresLowLatencyMonitor;
		}

		StorageManager::writeTrainInfo(*trainInfo);
		}

		void StatsLogProcessor::onWatchdogRollbackOccurredLocked(LogEvent* event) {
		pid_t pid = event->GetPid();
		uid_t uid = event->GetUid();
		if (!checkPermissionForIds(kPermissionDump, pid, uid) \|\|
		!checkPermissionForIds(kPermissionUsage, pid, uid)) {
		return;
		}
		// The Get* functions don't modify the status on success, they only write in
		// failure statuses, so we can use one status variable for all calls then
		// check if it is no longer NO_ERROR.
		status_t err = NO_ERROR;
		int32_t rollbackType = int32_t(event->GetInt(1 /rollback type field id/, &err));
		string packageName = string(event->GetString(2 /package name field id/, &err));

		if (err != NO_ERROR) {
		ALOGE("Failed to parse fields in watchdog rollback occurred log event");
		return;
		}

		vector<int64_t> experimentIds =
		processWatchdogRollbackOccurred(rollbackType, packageName);
		vector<uint8_t> experimentIdProto;
		writeExperimentIdsToProto(experimentIds, &experimentIdProto);

		#ifdef NEW_ENCODING_SCHEME
		event->updateValue(6 /experiment ids field id/, experimentIdProto, STORAGE);
		#else
		event->updateValue(6 /experiment ids field id/, experimentIdProto, STRING);
		#endif
		}

		vector<int64_t> StatsLogProcessor::processWatchdogRollbackOccurred(const int32_t rollbackTypeIn,
		const string& packageNameIn) {
		// If the package name is empty, we can't attribute it to any train, so
		// return early.
		if (packageNameIn.empty()) {
		return vector<int64_t>();
		}
		bool readTrainInfoSuccess = false;
		InstallTrainInfo trainInfoOnDisk;
		readTrainInfoSuccess = StorageManager::readTrainInfo(packageNameIn, trainInfoOnDisk);

		if (!readTrainInfoSuccess) {
		return vector<int64_t>();
		}

		if (trainInfoOnDisk.experimentIds.empty()) {
		return vector<int64_t>();
		}
		switch (rollbackTypeIn) {
		case android::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_INITIATE:
		trainInfoOnDisk.experimentIds.push_back(trainInfoOnDisk.experimentIds[0] + 4);
		StorageManager::writeTrainInfo(trainInfoOnDisk);
		break;
		case android::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS:
		trainInfoOnDisk.experimentIds.push_back(trainInfoOnDisk.experimentIds[0] + 5);
		StorageManager::writeTrainInfo(trainInfoOnDisk);
		break;
		}

		return trainInfoOnDisk.experimentIds;
		}

		void StatsLogProcessor::resetConfigs() {
		std::lock_guard<std::mutex> lock(mMetricsMutex);
		@@ -324,6 +405,12 @@ void StatsLogProcessor::OnLogEvent(LogEvent* event, int64_t elapsedRealtimeNs) {
		onBinaryPushStateChangedEventLocked(event);
		}

		// Hard-coded logic to update experiment ids on disk for certain rollback
		// types and fill the rollback atom with experiment ids
		if (event->GetTagId() == android::util::WATCHDOG_ROLLBACK_OCCURRED) {
		onWatchdogRollbackOccurredLocked(event);
		}

		#ifdef VERY_VERBOSE_PRINTING
		if (mPrintAllLogs) {
		ALOGI("%s", event->ToString().c_str());

cmds/statsd/src/StatsLogProcessor.h

+11 −2

Original line number	Diff line number	Diff line
		@@ -18,6 +18,7 @@

		#include <gtest/gtest_prod.h>
		#include "config/ConfigListener.h"
		#include "logd/LogEvent.h"
		#include "metrics/MetricsManager.h"
		#include "packages/UidMap.h"
		#include "external/StatsPullerManager.h"
		@@ -199,10 +200,18 @@ private:
		// Handler over the binary push state changed event.
		void onBinaryPushStateChangedEventLocked(LogEvent* event);

		// Handler over the watchdog rollback occurred event.
		void onWatchdogRollbackOccurredLocked(LogEvent* event);

		// Updates train info on disk based on binary push state changed info and
		// write disk info into parameters.
		void getAndUpdateTrainInfoOnDisk(int32_t state, int64_t* trainVersionCode,
		string* trainName, std::vector<int64_t>* experimentIds);
		void getAndUpdateTrainInfoOnDisk(bool is_rollback, InstallTrainInfo* trainInfoIn);

		// Gets experiment ids on disk for associated train and updates them
		// depending on rollback type. Then writes them back to disk and returns
		// them.
		std::vector<int64_t> processWatchdogRollbackOccurred(const int32_t rollbackTypeIn,
		const string& packageName);

		// Reset all configs.
		void resetConfigsLocked(const int64_t timestampNs);

cmds/statsd/src/StatsService.cpp

+8 −65

Original line number	Diff line number	Diff line
		@@ -1293,81 +1293,24 @@ Status StatsService::unregisterNativePullAtomCallback(int32_t atomTag) {
		return Status::ok();
		}

		Status StatsService::sendWatchdogRollbackOccurredAtom(const int32_t rollbackTypeIn,
		const android::String16& packageNameIn,
		const int64_t packageVersionCodeIn,
		const int32_t rollbackReasonIn,
		const android::String16&
		failingPackageNameIn) {
		// Note: We skip the usage stats op check here since we do not have a package name.
		// This is ok since we are overloading the usage_stats permission.
		// This method only sends data, it does not receive it.
		pid_t pid = IPCThreadState::self()->getCallingPid();
		uid_t uid = IPCThreadState::self()->getCallingUid();
		// Root, system, and shell always have access
		if (uid != AID_ROOT && uid != AID_SYSTEM && uid != AID_SHELL) {
		// Caller must be granted these permissions
		if (!checkPermission(kPermissionDump)) {
		return exception(binder::Status::EX_SECURITY,
		StringPrintf("UID %d / PID %d lacks permission %s", uid, pid,
		kPermissionDump));
		}
		if (!checkPermission(kPermissionUsage)) {
		return exception(binder::Status::EX_SECURITY,
		StringPrintf("UID %d / PID %d lacks permission %s", uid, pid,
		kPermissionUsage));
		}
		}

		android::util::stats_write(android::util::WATCHDOG_ROLLBACK_OCCURRED,
		rollbackTypeIn, String8(packageNameIn).string(), packageVersionCodeIn,
		rollbackReasonIn, String8(failingPackageNameIn).string());

		// Fast return to save disk read.
		if (rollbackTypeIn != android::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS
		&& rollbackTypeIn !=
		android::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_INITIATE) {
		return Status::ok();
		}

		bool readTrainInfoSuccess = false;
		InstallTrainInfo trainInfoOnDisk;
		readTrainInfoSuccess = StorageManager::readTrainInfo(trainInfoOnDisk);

		if (!readTrainInfoSuccess) {
		return Status::ok();
		}
		std::vector<int64_t> experimentIds = trainInfoOnDisk.experimentIds;
		if (experimentIds.empty()) {
		return Status::ok();
		}
		switch (rollbackTypeIn) {
		case android::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_INITIATE:
		experimentIds.push_back(experimentIds[0] + 4);
		break;
		case android::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS:
		experimentIds.push_back(experimentIds[0] + 5);
		break;
		}
		StorageManager::writeTrainInfo(trainInfoOnDisk.trainVersionCode, trainInfoOnDisk.trainName,
		trainInfoOnDisk.status, experimentIds);
		return Status::ok();
		}

		Status StatsService::getRegisteredExperimentIds(std::vector<int64_t>* experimentIdsOut) {
		ENFORCE_UID(AID_SYSTEM);
		// TODO: add verifier permission

		experimentIdsOut->clear();
		// Read the latest train info
		InstallTrainInfo trainInfo;
		if (!StorageManager::readTrainInfo(trainInfo)) {
		vector<InstallTrainInfo> trainInfoList = StorageManager::readAllTrainInfo();
		if (trainInfoList.empty()) {
		// No train info means no experiment IDs, return an empty list
		experimentIdsOut->clear();
		return Status::ok();
		}

		// Copy the experiment IDs to the out vector
		experimentIdsOut->assign(trainInfo.experimentIds.begin(), trainInfo.experimentIds.end());
		for (InstallTrainInfo& trainInfo : trainInfoList) {
		experimentIdsOut->insert(experimentIdsOut->end(),
		trainInfo.experimentIds.begin(),
		trainInfo.experimentIds.end());
		}
		return Status::ok();
		}