Merge "Update StatsLogProcessor to handle BinaryPushStateChanged"

This commit is contained in:
TreeHugger Robot
2020-02-05 19:15:29 +00:00
committed by Android (Google) Code Review
13 changed files with 245 additions and 158 deletions

View File

@@ -221,12 +221,6 @@ interface IStatsd {
*/
const int FLAG_REQUIRE_LOW_LATENCY_MONITOR = 0x04;
/**
* Logs an event for binary push for module updates.
*/
oneway void sendBinaryPushStateChangedAtom(in String trainName, in long trainVersionCode,
in int options, in int state, in long[] experimentId);
/**
* Logs an event for watchdog rollbacks.
*/

View File

@@ -64,6 +64,7 @@ cc_defaults {
"src/config/ConfigKey.cpp",
"src/config/ConfigListener.cpp",
"src/config/ConfigManager.cpp",
"src/experiment_ids.proto",
"src/external/GpuStatsPuller.cpp",
"src/external/Perfetto.cpp",
"src/external/PullResultReceiver.cpp",

View File

@@ -20,13 +20,17 @@
#include "StatsLogProcessor.h"
#include <android-base/file.h>
#include <cutils/multiuser.h>
#include <frameworks/base/cmds/statsd/src/active_config_list.pb.h>
#include <frameworks/base/cmds/statsd/src/experiment_ids.pb.h>
#include "android-base/stringprintf.h"
#include "atoms_info.h"
#include "external/StatsPullerManager.h"
#include "guardrail/StatsdStats.h"
#include "logd/LogEvent.h"
#include "metrics/CountMetricProducer.h"
#include "StatsService.h"
#include "state/StateManager.h"
#include "stats_log_util.h"
#include "stats_util.h"
@@ -68,6 +72,10 @@ const int FIELD_ID_STRINGS = 9;
// for ActiveConfigList
const int FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG = 1;
// for permissions checks
constexpr const char* kPermissionDump = "android.permission.DUMP";
constexpr const char* kPermissionUsage = "android.permission.PACKAGE_USAGE_STATS";
#define NS_PER_HOUR 3600 * NS_PER_SEC
#define STATS_ACTIVE_METRIC_DIR "/data/misc/stats-active-metric"
@@ -181,6 +189,115 @@ void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
}
}
void StatsLogProcessor::onBinaryPushStateChangedEventLocked(LogEvent* event) {
pid_t pid = event->GetPid();
uid_t uid = event->GetUid();
if (!checkPermissionForIds(kPermissionDump, pid, uid) ||
!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));
#ifdef NEW_ENCODING_SCHEME
std::vector<uint8_t> trainExperimentIdBytes =
event->GetStorage(7 /*experiment ids field id*/, &err4);
#else
string trainExperimentIdString = event->GetString(7 /*experiment ids field id*/, &err4);
#endif
if (err != NO_ERROR || err2 != NO_ERROR || err3 != NO_ERROR || err4 != NO_ERROR) {
ALOGE("Failed to parse fields in binary push state changed log event");
return;
}
ExperimentIds trainExperimentIds;
#ifdef NEW_ENCODING_SCHEME
if (!trainExperimentIds.ParseFromArray(trainExperimentIdBytes.data(),
trainExperimentIdBytes.size())) {
#else
if (!trainExperimentIds.ParseFromString(trainExperimentIdString)) {
#endif
ALOGE("Failed to parse experimentids in binary push state changed.");
return;
}
vector<int64_t> experimentIdVector = {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);
std::vector<uint8_t> trainExperimentIdProto;
writeExperimentIdsToProto(experimentIdVector, &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);
#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);
}
void StatsLogProcessor::getAndUpdateTrainInfoOnDisk(int32_t state,
int64_t* trainVersionCode,
string* trainName,
std::vector<int64_t>* experimentIds) {
bool readTrainInfoSuccess = false;
InstallTrainInfo trainInfoOnDisk;
readTrainInfoSuccess = StorageManager::readTrainInfo(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) {
// 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() &&
(trainInfoOnDisk.experimentIds.empty() ||
experimentIds->at(0) != trainInfoOnDisk.experimentIds[0])) {
resetExperimentIds = true;
}
}
// Find the right experiment IDs
if (!resetExperimentIds && readTrainInfoSuccess) {
*experimentIds = trainInfoOnDisk.experimentIds;
}
if (!experimentIds->empty()) {
int64_t firstId = experimentIds->at(0);
switch (state) {
case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALL_SUCCESS:
experimentIds->push_back(firstId + 1);
break;
case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_INITIATED:
experimentIds->push_back(firstId + 2);
break;
case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_SUCCESS:
experimentIds->push_back(firstId + 3);
break;
}
}
StorageManager::writeTrainInfo(*trainVersionCode, *trainName, state, *experimentIds);
}
void StatsLogProcessor::resetConfigs() {
std::lock_guard<std::mutex> lock(mMetricsMutex);
resetConfigsLocked(getElapsedRealtimeNs());
@@ -201,6 +318,12 @@ void StatsLogProcessor::OnLogEvent(LogEvent* event) {
void StatsLogProcessor::OnLogEvent(LogEvent* event, int64_t elapsedRealtimeNs) {
std::lock_guard<std::mutex> lock(mMetricsMutex);
// Hard-coded logic to update train info on disk and fill in any information
// this log event may be missing.
if (event->GetTagId() == android::util::BINARY_PUSH_STATE_CHANGED) {
onBinaryPushStateChangedEventLocked(event);
}
#ifdef VERY_VERBOSE_PRINTING
if (mPrintAllLogs) {
ALOGI("%s", event->ToString().c_str());

View File

@@ -196,6 +196,14 @@ private:
// Handler over the isolated uid change event.
void onIsolatedUidChangedEventLocked(const LogEvent& event);
// Handler over the binary push state changed event.
void onBinaryPushStateChangedEventLocked(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);
// Reset all configs.
void resetConfigsLocked(const int64_t timestampNs);
// Reset the specified configs.

View File

@@ -70,25 +70,12 @@ static binder::Status exception(uint32_t code, const std::string& msg) {
return binder::Status::fromExceptionCode(code, String8(msg.c_str()));
}
static bool checkPermission(const char* permission) {
sp<IStatsCompanionService> scs = getStatsCompanionService();
if (scs == nullptr) {
return false;
}
bool success;
pid_t pid = IPCThreadState::self()->getCallingPid();
uid_t uid = IPCThreadState::self()->getCallingUid();
binder::Status status = scs->checkPermission(String16(permission), pid, uid, &success);
if (!status.isOk()) {
return false;
}
return success;
return checkPermissionForIds(permission, pid, uid);
}
binder::Status checkUid(uid_t expectedUid) {
uid_t uid = IPCThreadState::self()->getCallingUid();
if (uid == expectedUid || uid == AID_ROOT) {
@@ -870,18 +857,8 @@ status_t StatsService::cmd_log_binary_push(int out, const Vector<String8>& args)
dprintf(out, "Incorrect number of argument supplied\n");
return UNKNOWN_ERROR;
}
android::String16 trainName = android::String16(args[1].c_str());
string trainName = string(args[1].c_str());
int64_t trainVersion = strtoll(args[2].c_str(), nullptr, 10);
int options = 0;
if (args[3] == "1") {
options = options | IStatsd::FLAG_REQUIRE_STAGING;
}
if (args[4] == "1") {
options = options | IStatsd::FLAG_ROLLBACK_ENABLED;
}
if (args[5] == "1") {
options = options | IStatsd::FLAG_REQUIRE_LOW_LATENCY_MONITOR;
}
int32_t state = atoi(args[6].c_str());
vector<int64_t> experimentIds;
if (argCount == 8) {
@@ -892,7 +869,10 @@ status_t StatsService::cmd_log_binary_push(int out, const Vector<String8>& args)
}
}
dprintf(out, "Logging BinaryPushStateChanged\n");
sendBinaryPushStateChangedAtom(trainName, trainVersion, options, state, experimentIds);
vector<uint8_t> experimentIdBytes;
writeExperimentIdsToProto(experimentIds, &experimentIdBytes);
LogEvent event(trainName, trainVersion, args[3], args[4], args[5], state, experimentIdBytes, 0);
mProcessor->OnLogEvent(&event);
return NO_ERROR;
}
@@ -1313,101 +1293,6 @@ Status StatsService::unregisterNativePullAtomCallback(int32_t atomTag) {
return Status::ok();
}
Status StatsService::sendBinaryPushStateChangedAtom(const android::String16& trainNameIn,
const int64_t trainVersionCodeIn,
const int options,
const int32_t state,
const std::vector<int64_t>& experimentIdsIn) {
// 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));
}
}
bool readTrainInfoSuccess = false;
InstallTrainInfo trainInfoOnDisk;
readTrainInfoSuccess = StorageManager::readTrainInfo(trainInfoOnDisk);
bool resetExperimentIds = false;
int64_t trainVersionCode = trainVersionCodeIn;
std::string trainNameUtf8 = std::string(String8(trainNameIn).string());
if (readTrainInfoSuccess) {
// Keep the old train version if we received an empty version.
if (trainVersionCodeIn == -1) {
trainVersionCode = trainInfoOnDisk.trainVersionCode;
} else if (trainVersionCodeIn != 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 (trainNameUtf8.size() == 0) {
trainNameUtf8 = trainInfoOnDisk.trainName;
} else if (trainNameUtf8 != trainInfoOnDisk.trainName) {
// Reset experiment ids if we received a new valid train name.
resetExperimentIds = true;
}
// Reset if we received a different experiment id.
if (!experimentIdsIn.empty() &&
(trainInfoOnDisk.experimentIds.empty() ||
experimentIdsIn[0] != trainInfoOnDisk.experimentIds[0])) {
resetExperimentIds = true;
}
}
// Find the right experiment IDs
std::vector<int64_t> experimentIds;
if (resetExperimentIds || !readTrainInfoSuccess) {
experimentIds = experimentIdsIn;
} else {
experimentIds = trainInfoOnDisk.experimentIds;
}
if (!experimentIds.empty()) {
int64_t firstId = experimentIds[0];
switch (state) {
case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALL_SUCCESS:
experimentIds.push_back(firstId + 1);
break;
case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_INITIATED:
experimentIds.push_back(firstId + 2);
break;
case android::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_SUCCESS:
experimentIds.push_back(firstId + 3);
break;
}
}
// Flatten the experiment IDs to proto
vector<uint8_t> experimentIdsProtoBuffer;
writeExperimentIdsToProto(experimentIds, &experimentIdsProtoBuffer);
StorageManager::writeTrainInfo(trainVersionCode, trainNameUtf8, state, experimentIds);
userid_t userId = multiuser_get_user_id(uid);
bool requiresStaging = options & IStatsd::FLAG_REQUIRE_STAGING;
bool rollbackEnabled = options & IStatsd::FLAG_ROLLBACK_ENABLED;
bool requiresLowLatencyMonitor = options & IStatsd::FLAG_REQUIRE_LOW_LATENCY_MONITOR;
LogEvent event(trainNameUtf8, trainVersionCode, requiresStaging, rollbackEnabled,
requiresLowLatencyMonitor, state, experimentIdsProtoBuffer, userId);
mProcessor->OnLogEvent(&event);
return Status::ok();
}
Status StatsService::sendWatchdogRollbackOccurredAtom(const int32_t rollbackTypeIn,
const android::String16& packageNameIn,
const int64_t packageVersionCodeIn,

View File

@@ -192,16 +192,6 @@ public:
*/
virtual Status unregisterNativePullAtomCallback(int32_t atomTag) override;
/**
* Binder call to log BinaryPushStateChanged atom.
*/
virtual Status sendBinaryPushStateChangedAtom(
const android::String16& trainNameIn,
const int64_t trainVersionCodeIn,
const int options,
const int32_t state,
const std::vector<int64_t>& experimentIdsIn) override;
/**
* Binder call to log WatchdogRollbackOccurred atom.
*/

View File

@@ -3709,6 +3709,7 @@ message FlagFlipUpdateOccurred {
/**
* Potential experiment ids that goes with a train install.
* Should be kept in sync with experiment_ids.proto.
*/
message TrainExperimentIds {
repeated int64 experiment_id = 1;

View File

@@ -0,0 +1,29 @@
/*
* Copyright (C) 2020 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
syntax = "proto2";
package android.os.statsd;
option java_package = "com.android.internal.os";
option java_outer_classname = "ExperimentIdsProto";
// StatsLogProcessor uses the proto to parse experiment ids from
// BinaryPushStateChanged atoms. This needs to be in sync with
// TrainExperimentIds in atoms.proto.
message ExperimentIds {
repeated int64 experiment_id = 1;
}

View File

@@ -837,6 +837,26 @@ float LogEvent::GetFloat(size_t key, status_t* err) const {
return 0.0;
}
std::vector<uint8_t> LogEvent::GetStorage(size_t key, status_t* err) const {
int field = getSimpleField(key);
for (const auto& value : mValues) {
if (value.mField.getField() == field) {
if (value.mValue.getType() == STORAGE) {
return value.mValue.storage_value;
} else {
*err = BAD_TYPE;
return vector<uint8_t>();
}
}
if ((size_t)value.mField.getPosAtDepth(0) > key) {
break;
}
}
*err = BAD_INDEX;
return vector<uint8_t>();
}
string LogEvent::ToString() const {
string result;
result += StringPrintf("{ uid(%d) %lld %lld (%d)", mLogUid, (long long)mLogdTimestampNs,

View File

@@ -144,6 +144,7 @@ public:
const char* GetString(size_t key, status_t* err) const;
bool GetBool(size_t key, status_t* err) const;
float GetFloat(size_t key, status_t* err) const;
std::vector<uint8_t> GetStorage(size_t key, status_t* err) const;
/**
* Write test data to the LogEvent. This can only be used when the LogEvent is constructed
@@ -214,6 +215,22 @@ public:
return LogEvent(*this);
}
template <class T>
status_t updateValue(size_t key, T& value, Type type) {
int field = getSimpleField(key);
for (auto& fieldValue : mValues) {
if (fieldValue.mField.getField() == field) {
if (fieldValue.mValue.getType() == type) {
fieldValue.mValue = Value(value);
return OK;
} else {
return BAD_TYPE;
}
}
}
return BAD_INDEX;
}
private:
/**
* Only use this if copy is absolutely needed.

View File

@@ -21,6 +21,8 @@
#include <set>
#include <utils/SystemClock.h>
#include "statscompanion_util.h"
using android::util::AtomsInfo;
using android::util::FIELD_COUNT_REPEATED;
using android::util::FIELD_TYPE_BOOL;
@@ -584,6 +586,21 @@ int64_t MillisToNano(const int64_t millis) {
return millis * 1000000;
}
bool checkPermissionForIds(const char* permission, pid_t pid, uid_t uid) {
sp<IStatsCompanionService> scs = getStatsCompanionService();
if (scs == nullptr) {
return false;
}
bool success;
binder::Status status = scs->checkPermission(String16(permission), pid, uid, &success);
if (!status.isOk()) {
return false;
}
return success;
}
} // namespace statsd
} // namespace os
} // namespace android

View File

@@ -95,6 +95,9 @@ bool parseProtoOutputStream(util::ProtoOutputStream& protoOutput, T* message) {
// Returns the truncated timestamp to the nearest 5 minutes if needed.
int64_t truncateTimestampIfNecessary(int atomId, int64_t timestampNs);
// Checks permission for given pid and uid.
bool checkPermissionForIds(const char* permission, pid_t pid, uid_t uid);
inline bool isVendorPulledAtom(int atomId) {
return atomId >= StatsdStats::kVendorPulledAtomStartTag && atomId < StatsdStats::kMaxAtomTag;
}

View File

@@ -27,6 +27,7 @@ import android.content.Context;
import android.os.IStatsd;
import android.os.RemoteException;
import android.os.ServiceManager;
import android.util.proto.ProtoOutputStream;
import com.android.internal.util.FrameworkStatsLog;
@@ -37,6 +38,7 @@ import com.android.internal.util.FrameworkStatsLog;
public final class StatsLog {
private static final String TAG = "StatsLog";
private static final boolean DEBUG = false;
private static final int EXPERIMENT_IDS_FIELD_ID = 1;
private static IStatsd sService;
@@ -152,28 +154,25 @@ public final class StatsLog {
public static boolean logBinaryPushStateChanged(@NonNull String trainName,
long trainVersionCode, int options, int state,
@NonNull long[] experimentIds) {
synchronized (sLogLock) {
try {
IStatsd service = getIStatsdLocked();
if (service == null) {
if (DEBUG) {
Slog.d(TAG, "Failed to find statsd when logging event");
}
return false;
}
service.sendBinaryPushStateChangedAtom(
trainName, trainVersionCode, options, state, experimentIds);
return true;
} catch (RemoteException e) {
sService = null;
if (DEBUG) {
Slog.d(TAG,
"Failed to connect to StatsCompanionService when logging "
+ "BinaryPushStateChanged");
}
return false;
}
ProtoOutputStream proto = new ProtoOutputStream();
for (long id : experimentIds) {
proto.write(
ProtoOutputStream.FIELD_TYPE_INT64
| ProtoOutputStream.FIELD_COUNT_REPEATED
| EXPERIMENT_IDS_FIELD_ID,
id);
}
FrameworkStatsLog.write(FrameworkStatsLog.BINARY_PUSH_STATE_CHANGED,
trainName,
trainVersionCode,
(options & IStatsd.FLAG_REQUIRE_STAGING) > 0,
(options & IStatsd.FLAG_ROLLBACK_ENABLED) > 0,
(options & IStatsd.FLAG_REQUIRE_LOW_LATENCY_MONITOR) > 0,
state,
proto.getBytes(),
0,
0);
return true;
}
/**