Merge "StatsdStats: improve activation time logging" into qt-dev

am: 26b6ef7904

Change-Id: I3c9be295caf4acb672bed44ba47a4d67a44ed52a
This commit is contained in:
Tej Singh
2019-06-27 19:19:45 -07:00
committed by android-build-merger
6 changed files with 109 additions and 0 deletions

View File

@@ -269,6 +269,7 @@ void StatsLogProcessor::OnLogEvent(LogEvent* event) {
if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) {
if (currentTimestampNs - lastBroadcastTime->second <
StatsdStats::kMinActivationBroadcastPeriodNs) {
StatsdStats::getInstance().noteActivationBroadcastGuardrailHit(uid);
VLOG("StatsD would've sent an activation broadcast but the rate limit stopped us.");
return;
}

View File

@@ -51,6 +51,7 @@ const int FIELD_ID_PERIODIC_ALARM_STATS = 12;
const int FIELD_ID_SYSTEM_SERVER_RESTART = 15;
const int FIELD_ID_LOGGER_ERROR_STATS = 16;
const int FIELD_ID_OVERFLOW = 18;
const int FIELD_ID_ACTIVATION_BROADCAST_GUARDRAIL = 19;
const int FIELD_ID_ATOM_STATS_TAG = 1;
const int FIELD_ID_ATOM_STATS_COUNT = 2;
@@ -109,6 +110,9 @@ const int FIELD_ID_UID_MAP_BYTES_USED = 2;
const int FIELD_ID_UID_MAP_DROPPED_CHANGES = 3;
const int FIELD_ID_UID_MAP_DELETED_APPS = 4;
const int FIELD_ID_ACTIVATION_BROADCAST_GUARDRAIL_UID = 1;
const int FIELD_ID_ACTIVATION_BROADCAST_GUARDRAIL_TIME = 2;
const std::map<int, std::pair<size_t, size_t>> StatsdStats::kAtomDimensionKeySizeLimitMap = {
{android::util::BINDER_CALLS, {6000, 10000}},
{android::util::LOOPER_STATS, {1500, 2500}},
@@ -236,6 +240,19 @@ void StatsdStats::noteActiveStatusChanged(const ConfigKey& key, bool activated,
vec.push_back(timeSec);
}
void StatsdStats::noteActivationBroadcastGuardrailHit(const int uid) {
noteActivationBroadcastGuardrailHit(uid, getWallClockSec());
}
void StatsdStats::noteActivationBroadcastGuardrailHit(const int uid, const int32_t timeSec) {
lock_guard<std::mutex> lock(mLock);
auto& guardrailTimes = mActivationBroadcastGuardrailStats[uid];
if (guardrailTimes.size() == kMaxTimestampCount) {
guardrailTimes.pop_front();
}
guardrailTimes.push_back(timeSec);
}
void StatsdStats::noteDataDropped(const ConfigKey& key, const size_t totalBytes) {
noteDataDropped(key, totalBytes, getWallClockSec());
}
@@ -590,6 +607,7 @@ void StatsdStats::resetInternalLocked() {
pullStats.second.unregisteredCount = 0;
}
mAtomMetricStats.clear();
mActivationBroadcastGuardrailStats.clear();
}
string buildTimeString(int64_t timeSec) {
@@ -758,6 +776,17 @@ void StatsdStats::dumpStats(int out) const {
dprintf(out, "Event queue overflow: %d; MaxHistoryNs: %lld; MinHistoryNs: %lld\n",
mOverflowCount, (long long)mMaxQueueHistoryNs, (long long)mMinQueueHistoryNs);
if (mActivationBroadcastGuardrailStats.size() > 0) {
dprintf(out, "********mActivationBroadcastGuardrail stats***********\n");
for (const auto& pair: mActivationBroadcastGuardrailStats) {
dprintf(out, "Uid %d: Times: ", pair.first);
for (const auto& guardrailHitTime : pair.second) {
dprintf(out, "%d ", guardrailHitTime);
}
}
dprintf(out, "\n");
}
}
void addConfigStatsToProto(const ConfigStats& configStats, ProtoOutputStream* proto) {
@@ -959,6 +988,20 @@ void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) {
restart);
}
for (const auto& pair: mActivationBroadcastGuardrailStats) {
uint64_t token = proto.start(FIELD_TYPE_MESSAGE |
FIELD_ID_ACTIVATION_BROADCAST_GUARDRAIL |
FIELD_COUNT_REPEATED);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_ACTIVATION_BROADCAST_GUARDRAIL_UID,
(int32_t) pair.first);
for (const auto& guardrailHitTime : pair.second) {
proto.write(FIELD_TYPE_INT32 | FIELD_ID_ACTIVATION_BROADCAST_GUARDRAIL_TIME |
FIELD_COUNT_REPEATED,
guardrailHitTime);
}
proto.end(token);
}
output->clear();
size_t bufferSize = proto.size();
output->resize(bufferSize);

View File

@@ -444,6 +444,12 @@ public:
* the queue */
void noteEventQueueOverflow(int64_t oldestEventTimestampNs);
/**
* Reports that the activation broadcast guardrail was hit for this uid. Namely, the broadcast
* should have been sent, but instead was skipped due to hitting the guardrail.
*/
void noteActivationBroadcastGuardrailHit(const int uid);
/**
* Reset the historical stats. Including all stats in icebox, and the tracked stats about
* metrics, matchers, and atoms. The active configs will be kept and StatsdStats will continue
@@ -532,6 +538,10 @@ private:
// Maps metric ID to its stats. The size is capped by the number of metrics.
std::map<int64_t, AtomMetricStats> mAtomMetricStats;
// Maps uids to times when the activation changed broadcast not sent due to hitting the
// guardrail. The size is capped by the number of configs, and up to 20 times per uid.
std::map<int, std::list<int32_t>> mActivationBroadcastGuardrailStats;
struct LogLossStats {
LogLossStats(int32_t sec, int32_t count, int32_t error, int32_t tag, int32_t uid,
int32_t pid)
@@ -588,6 +598,8 @@ private:
void noteActiveStatusChanged(const ConfigKey& key, bool activate, int32_t timeSec);
void noteActivationBroadcastGuardrailHit(const int uid, int32_t timeSec);
void addToIceBoxLocked(std::shared_ptr<ConfigStats>& stats);
/**
@@ -607,6 +619,7 @@ private:
FRIEND_TEST(StatsdStatsTest, TestSystemServerCrash);
FRIEND_TEST(StatsdStatsTest, TestPullAtomStats);
FRIEND_TEST(StatsdStatsTest, TestAtomMetricsStats);
FRIEND_TEST(StatsdStatsTest, TestActivationBroadcastGuardrailHit);
};
} // namespace statsd

View File

@@ -521,6 +521,10 @@ void MetricsManager::loadActiveConfig(const ActiveConfig& config, int64_t curren
if (metric->getMetricId() == activeMetric.id()) {
VLOG("Setting active metric: %lld", (long long)metric->getMetricId());
metric->loadActiveMetric(activeMetric, currentTimeNs);
if (!mIsActive && metric->isActive()) {
StatsdStats::getInstance().noteActiveStatusChanged(mConfigKey,
/*activate=*/ true);
}
mIsActive |= metric->isActive();
}
}

View File

@@ -470,6 +470,13 @@ message StatsdStatsReport {
}
optional EventQueueOverflow queue_overflow = 18;
message ActivationBroadcastGuardrail {
optional int32 uid = 1;
repeated int32 guardrail_met_sec = 2;
}
repeated ActivationBroadcastGuardrail activation_guardrail_stats = 19;
}
message AlertTriggerDetails {

View File

@@ -445,6 +445,47 @@ TEST(StatsdStatsTest, TestSystemServerCrash) {
EXPECT_EQ(StatsdStats::kMaxSystemServerRestarts + 1, report.system_restart_sec(maxCount - 1));
}
TEST(StatsdStatsTest, TestActivationBroadcastGuardrailHit) {
StatsdStats stats;
int uid1 = 1;
int uid2 = 2;
stats.noteActivationBroadcastGuardrailHit(uid1, 10);
stats.noteActivationBroadcastGuardrailHit(uid1, 20);
// Test that we only keep 20 timestamps.
for (int i = 0; i < 100; i++) {
stats.noteActivationBroadcastGuardrailHit(uid2, i);
}
vector<uint8_t> output;
stats.dumpStats(&output, false);
StatsdStatsReport report;
EXPECT_TRUE(report.ParseFromArray(&output[0], output.size()));
EXPECT_EQ(2, report.activation_guardrail_stats_size());
bool uid1Good = false;
bool uid2Good = false;
for (const auto& guardrailTimes : report.activation_guardrail_stats()) {
if (uid1 == guardrailTimes.uid()) {
uid1Good = true;
EXPECT_EQ(2, guardrailTimes.guardrail_met_sec_size());
EXPECT_EQ(10, guardrailTimes.guardrail_met_sec(0));
EXPECT_EQ(20, guardrailTimes.guardrail_met_sec(1));
} else if (uid2 == guardrailTimes.uid()) {
int maxCount = StatsdStats::kMaxTimestampCount;
uid2Good = true;
EXPECT_EQ(maxCount, guardrailTimes.guardrail_met_sec_size());
for (int i = 0; i < maxCount; i++) {
EXPECT_EQ(100 - maxCount + i, guardrailTimes.guardrail_met_sec(i));
}
} else {
FAIL() << "Unexpected uid.";
}
}
EXPECT_TRUE(uid1Good);
EXPECT_TRUE(uid2Good);
}
} // namespace statsd
} // namespace os
} // namespace android