blob: e2e94263ed8fa9ad9f706b5513864e9491f51a99 [file] [log] [blame]
/*
* Copyright 2017, 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.
*/
#define DEBUG false // STOPSHIP if true
#include "Log.h"
#include "StatsdStats.h"
#include <android/util/ProtoOutputStream.h>
#include "../stats_log_util.h"
#include "statslog.h"
namespace android {
namespace os {
namespace statsd {
using android::util::FIELD_COUNT_REPEATED;
using android::util::FIELD_TYPE_BOOL;
using android::util::FIELD_TYPE_FLOAT;
using android::util::FIELD_TYPE_INT32;
using android::util::FIELD_TYPE_INT64;
using android::util::FIELD_TYPE_MESSAGE;
using android::util::FIELD_TYPE_STRING;
using android::util::ProtoOutputStream;
using std::lock_guard;
using std::map;
using std::string;
using std::vector;
const int FIELD_ID_BEGIN_TIME = 1;
const int FIELD_ID_END_TIME = 2;
const int FIELD_ID_CONFIG_STATS = 3;
const int FIELD_ID_ATOM_STATS = 7;
const int FIELD_ID_UIDMAP_STATS = 8;
const int FIELD_ID_ANOMALY_ALARM_STATS = 9;
const int FIELD_ID_PULLED_ATOM_STATS = 10;
const int FIELD_ID_LOGGER_ERROR_STATS = 11;
const int FIELD_ID_MATCHER_STATS_NAME = 1;
const int FIELD_ID_MATCHER_STATS_COUNT = 2;
const int FIELD_ID_CONDITION_STATS_NAME = 1;
const int FIELD_ID_CONDITION_STATS_COUNT = 2;
const int FIELD_ID_METRIC_STATS_NAME = 1;
const int FIELD_ID_METRIC_STATS_COUNT = 2;
const int FIELD_ID_ATOM_STATS_TAG = 1;
const int FIELD_ID_ATOM_STATS_COUNT = 2;
const int FIELD_ID_ANOMALY_ALARMS_REGISTERED = 1;
const int FIELD_ID_LOGGER_STATS_TIME = 1;
const int FIELD_ID_LOGGER_STATS_ERROR_CODE = 2;
std::map<int, long> StatsdStats::kPullerCooldownMap = {
{android::util::KERNEL_WAKELOCK, 1},
{android::util::WIFI_BYTES_TRANSFER, 1},
{android::util::MOBILE_BYTES_TRANSFER, 1},
{android::util::WIFI_BYTES_TRANSFER_BY_FG_BG, 1},
{android::util::MOBILE_BYTES_TRANSFER_BY_FG_BG, 1},
{android::util::SUBSYSTEM_SLEEP_STATE, 1},
{android::util::CPU_TIME_PER_FREQ, 1},
{android::util::CPU_TIME_PER_UID, 1},
{android::util::CPU_TIME_PER_UID_FREQ, 1},
};
// TODO: add stats for pulled atoms.
StatsdStats::StatsdStats() {
mPushedAtomStats.resize(android::util::kMaxPushedAtomId + 1);
mStartTimeSec = getWallClockSec();
}
StatsdStats& StatsdStats::getInstance() {
static StatsdStats statsInstance;
return statsInstance;
}
void StatsdStats::addToIceBoxLocked(const StatsdStatsReport_ConfigStats& stats) {
// The size of mIceBox grows strictly by one at a time. It won't be > kMaxIceBoxSize.
if (mIceBox.size() == kMaxIceBoxSize) {
mIceBox.pop_front();
}
mIceBox.push_back(stats);
}
void StatsdStats::noteConfigReceived(const ConfigKey& key, int metricsCount, int conditionsCount,
int matchersCount, int alertsCount, bool isValid) {
lock_guard<std::mutex> lock(mLock);
int32_t nowTimeSec = getWallClockSec();
// If there is an existing config for the same key, icebox the old config.
noteConfigRemovedInternalLocked(key);
StatsdStatsReport_ConfigStats configStats;
configStats.set_uid(key.GetUid());
configStats.set_id(key.GetId());
configStats.set_creation_time_sec(nowTimeSec);
configStats.set_metric_count(metricsCount);
configStats.set_condition_count(conditionsCount);
configStats.set_matcher_count(matchersCount);
configStats.set_alert_count(alertsCount);
configStats.set_is_valid(isValid);
if (isValid) {
mConfigStats[key] = configStats;
} else {
configStats.set_deletion_time_sec(nowTimeSec);
addToIceBoxLocked(configStats);
}
}
void StatsdStats::noteConfigRemovedInternalLocked(const ConfigKey& key) {
auto it = mConfigStats.find(key);
if (it != mConfigStats.end()) {
int32_t nowTimeSec = getWallClockSec();
it->second.set_deletion_time_sec(nowTimeSec);
// Add condition stats, metrics stats, matcher stats, alert stats
addSubStatsToConfigLocked(key, it->second);
// Remove them after they are added to the config stats.
mMatcherStats.erase(key);
mMetricsStats.erase(key);
mAlertStats.erase(key);
mConditionStats.erase(key);
addToIceBoxLocked(it->second);
mConfigStats.erase(it);
}
}
void StatsdStats::noteConfigRemoved(const ConfigKey& key) {
lock_guard<std::mutex> lock(mLock);
noteConfigRemovedInternalLocked(key);
}
void StatsdStats::noteBroadcastSent(const ConfigKey& key) {
noteBroadcastSent(key, getWallClockSec());
}
void StatsdStats::noteBroadcastSent(const ConfigKey& key, int32_t timeSec) {
lock_guard<std::mutex> lock(mLock);
auto it = mConfigStats.find(key);
if (it == mConfigStats.end()) {
ALOGE("Config key %s not found!", key.ToString().c_str());
return;
}
if (it->second.broadcast_sent_time_sec_size() >= kMaxTimestampCount) {
auto timestampList = it->second.mutable_broadcast_sent_time_sec();
// This is O(N) operation. It shouldn't happen often, and N is only 20.
timestampList->erase(timestampList->begin());
}
it->second.add_broadcast_sent_time_sec(timeSec);
}
void StatsdStats::noteDataDropped(const ConfigKey& key) {
noteDataDropped(key, getWallClockSec());
}
void StatsdStats::noteDataDropped(const ConfigKey& key, int32_t timeSec) {
lock_guard<std::mutex> lock(mLock);
auto it = mConfigStats.find(key);
if (it == mConfigStats.end()) {
ALOGE("Config key %s not found!", key.ToString().c_str());
return;
}
if (it->second.data_drop_time_sec_size() >= kMaxTimestampCount) {
auto timestampList = it->second.mutable_data_drop_time_sec();
// This is O(N) operation. It shouldn't happen often, and N is only 20.
timestampList->erase(timestampList->begin());
}
it->second.add_data_drop_time_sec(timeSec);
}
void StatsdStats::noteMetricsReportSent(const ConfigKey& key) {
noteMetricsReportSent(key, getWallClockSec());
}
void StatsdStats::noteMetricsReportSent(const ConfigKey& key, int32_t timeSec) {
lock_guard<std::mutex> lock(mLock);
auto it = mConfigStats.find(key);
if (it == mConfigStats.end()) {
ALOGE("Config key %s not found!", key.ToString().c_str());
return;
}
if (it->second.dump_report_time_sec_size() >= kMaxTimestampCount) {
auto timestampList = it->second.mutable_dump_report_time_sec();
// This is O(N) operation. It shouldn't happen often, and N is only 20.
timestampList->erase(timestampList->begin());
}
it->second.add_dump_report_time_sec(timeSec);
}
void StatsdStats::noteUidMapDropped(int snapshots, int deltas) {
lock_guard<std::mutex> lock(mLock);
mUidMapStats.set_dropped_snapshots(mUidMapStats.dropped_snapshots() + snapshots);
mUidMapStats.set_dropped_changes(mUidMapStats.dropped_changes() + deltas);
}
void StatsdStats::setUidMapSnapshots(int snapshots) {
lock_guard<std::mutex> lock(mLock);
mUidMapStats.set_snapshots(snapshots);
}
void StatsdStats::setUidMapChanges(int changes) {
lock_guard<std::mutex> lock(mLock);
mUidMapStats.set_changes(changes);
}
void StatsdStats::setCurrentUidMapMemory(int bytes) {
lock_guard<std::mutex> lock(mLock);
mUidMapStats.set_bytes_used(bytes);
}
void StatsdStats::noteConditionDimensionSize(const ConfigKey& key, const int64_t& id, int size) {
lock_guard<std::mutex> lock(mLock);
// if name doesn't exist before, it will create the key with count 0.
auto& conditionSizeMap = mConditionStats[key];
if (size > conditionSizeMap[id]) {
conditionSizeMap[id] = size;
}
}
void StatsdStats::noteMetricDimensionSize(const ConfigKey& key, const int64_t& id, int size) {
lock_guard<std::mutex> lock(mLock);
// if name doesn't exist before, it will create the key with count 0.
auto& metricsDimensionMap = mMetricsStats[key];
if (size > metricsDimensionMap[id]) {
metricsDimensionMap[id] = size;
}
}
void StatsdStats::noteMatcherMatched(const ConfigKey& key, const int64_t& id) {
lock_guard<std::mutex> lock(mLock);
auto& matcherStats = mMatcherStats[key];
matcherStats[id]++;
}
void StatsdStats::noteAnomalyDeclared(const ConfigKey& key, const int64_t& id) {
lock_guard<std::mutex> lock(mLock);
auto& alertStats = mAlertStats[key];
alertStats[id]++;
}
void StatsdStats::noteRegisteredAnomalyAlarmChanged() {
lock_guard<std::mutex> lock(mLock);
mAnomalyAlarmRegisteredStats++;
}
void StatsdStats::updateMinPullIntervalSec(int pullAtomId, long intervalSec) {
lock_guard<std::mutex> lock(mLock);
mPulledAtomStats[pullAtomId].minPullIntervalSec = intervalSec;
}
void StatsdStats::notePull(int pullAtomId) {
lock_guard<std::mutex> lock(mLock);
mPulledAtomStats[pullAtomId].totalPull++;
}
void StatsdStats::notePullFromCache(int pullAtomId) {
lock_guard<std::mutex> lock(mLock);
mPulledAtomStats[pullAtomId].totalPullFromCache++;
}
void StatsdStats::noteAtomLogged(int atomId, int32_t timeSec) {
lock_guard<std::mutex> lock(mLock);
if (atomId > android::util::kMaxPushedAtomId) {
ALOGW("not interested in atom %d", atomId);
return;
}
mPushedAtomStats[atomId]++;
}
void StatsdStats::noteLoggerError(int error) {
lock_guard<std::mutex> lock(mLock);
// grows strictly one at a time. so it won't > kMaxLoggerErrors
if (mLoggerErrors.size() == kMaxLoggerErrors) {
mLoggerErrors.pop_front();
}
mLoggerErrors.push_back(std::make_pair(getWallClockSec(), error));
}
void StatsdStats::reset() {
lock_guard<std::mutex> lock(mLock);
resetInternalLocked();
}
void StatsdStats::resetInternalLocked() {
// Reset the historical data, but keep the active ConfigStats
mStartTimeSec = getWallClockSec();
mIceBox.clear();
mConditionStats.clear();
mMetricsStats.clear();
std::fill(mPushedAtomStats.begin(), mPushedAtomStats.end(), 0);
mAlertStats.clear();
mAnomalyAlarmRegisteredStats = 0;
mMatcherStats.clear();
mLoggerErrors.clear();
for (auto& config : mConfigStats) {
config.second.clear_broadcast_sent_time_sec();
config.second.clear_data_drop_time_sec();
config.second.clear_dump_report_time_sec();
config.second.clear_matcher_stats();
config.second.clear_condition_stats();
config.second.clear_metric_stats();
config.second.clear_alert_stats();
}
}
void StatsdStats::addSubStatsToConfigLocked(const ConfigKey& key,
StatsdStatsReport_ConfigStats& configStats) {
// Add matcher stats
if (mMatcherStats.find(key) != mMatcherStats.end()) {
const auto& matcherStats = mMatcherStats[key];
for (const auto& stats : matcherStats) {
auto output = configStats.add_matcher_stats();
output->set_id(stats.first);
output->set_matched_times(stats.second);
VLOG("matcher %lld matched %d times",
(long long)stats.first, stats.second);
}
}
// Add condition stats
if (mConditionStats.find(key) != mConditionStats.end()) {
const auto& conditionStats = mConditionStats[key];
for (const auto& stats : conditionStats) {
auto output = configStats.add_condition_stats();
output->set_id(stats.first);
output->set_max_tuple_counts(stats.second);
VLOG("condition %lld max output tuple size %d",
(long long)stats.first, stats.second);
}
}
// Add metrics stats
if (mMetricsStats.find(key) != mMetricsStats.end()) {
const auto& conditionStats = mMetricsStats[key];
for (const auto& stats : conditionStats) {
auto output = configStats.add_metric_stats();
output->set_id(stats.first);
output->set_max_tuple_counts(stats.second);
VLOG("metrics %lld max output tuple size %d",
(long long)stats.first, stats.second);
}
}
// Add anomaly detection alert stats
if (mAlertStats.find(key) != mAlertStats.end()) {
const auto& alertStats = mAlertStats[key];
for (const auto& stats : alertStats) {
auto output = configStats.add_alert_stats();
output->set_id(stats.first);
output->set_alerted_times(stats.second);
VLOG("alert %lld declared %d times", (long long)stats.first, stats.second);
}
}
}
void StatsdStats::dumpStats(FILE* out) const {
lock_guard<std::mutex> lock(mLock);
time_t t = mStartTimeSec;
struct tm* tm = localtime(&t);
char timeBuffer[80];
strftime(timeBuffer, sizeof(timeBuffer), "%Y-%m-%d %I:%M%p\n", tm);
fprintf(out, "Stats collection start second: %s\n", timeBuffer);
fprintf(out, "%lu Config in icebox: \n", (unsigned long)mIceBox.size());
for (const auto& configStats : mIceBox) {
fprintf(out,
"Config {%d-%lld}: creation=%d, deletion=%d, #metric=%d, #condition=%d, "
"#matcher=%d, #alert=%d, valid=%d\n",
configStats.uid(), (long long)configStats.id(), configStats.creation_time_sec(),
configStats.deletion_time_sec(), configStats.metric_count(),
configStats.condition_count(), configStats.matcher_count(),
configStats.alert_count(), configStats.is_valid());
for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) {
fprintf(out, "\tbroadcast time: %d\n", broadcastTime);
}
for (const auto& dataDropTime : configStats.data_drop_time_sec()) {
fprintf(out, "\tdata drop time: %d\n", dataDropTime);
}
}
fprintf(out, "%lu Active Configs\n", (unsigned long)mConfigStats.size());
for (auto& pair : mConfigStats) {
auto& key = pair.first;
auto& configStats = pair.second;
fprintf(out,
"Config {%d-%lld}: creation=%d, deletion=%d, #metric=%d, #condition=%d, "
"#matcher=%d, #alert=%d, valid=%d\n",
configStats.uid(), (long long)configStats.id(), configStats.creation_time_sec(),
configStats.deletion_time_sec(), configStats.metric_count(),
configStats.condition_count(), configStats.matcher_count(),
configStats.alert_count(), configStats.is_valid());
for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) {
fprintf(out, "\tbroadcast time: %d\n", broadcastTime);
}
for (const auto& dataDropTime : configStats.data_drop_time_sec()) {
fprintf(out, "\tdata drop time: %d\n", dataDropTime);
}
for (const auto& dumpTime : configStats.dump_report_time_sec()) {
fprintf(out, "\tdump report time: %d\n", dumpTime);
}
// Add matcher stats
auto matcherIt = mMatcherStats.find(key);
if (matcherIt != mMatcherStats.end()) {
const auto& matcherStats = matcherIt->second;
for (const auto& stats : matcherStats) {
fprintf(out, "matcher %lld matched %d times\n", (long long)stats.first,
stats.second);
}
}
// Add condition stats
auto conditionIt = mConditionStats.find(key);
if (conditionIt != mConditionStats.end()) {
const auto& conditionStats = conditionIt->second;
for (const auto& stats : conditionStats) {
fprintf(out, "condition %lld max output tuple size %d\n", (long long)stats.first,
stats.second);
}
}
// Add metrics stats
auto metricIt = mMetricsStats.find(key);
if (metricIt != mMetricsStats.end()) {
const auto& conditionStats = metricIt->second;
for (const auto& stats : conditionStats) {
fprintf(out, "metrics %lld max output tuple size %d\n", (long long)stats.first,
stats.second);
}
}
// Add anomaly detection alert stats
auto alertIt = mAlertStats.find(key);
if (alertIt != mAlertStats.end()) {
const auto& alertStats = alertIt->second;
for (const auto& stats : alertStats) {
fprintf(out, "alert %lld declared %d times\n", (long long)stats.first,
stats.second);
}
}
}
fprintf(out, "********Pushed Atom stats***********\n");
const size_t atomCounts = mPushedAtomStats.size();
for (size_t i = 2; i < atomCounts; i++) {
if (mPushedAtomStats[i] > 0) {
fprintf(out, "Atom %lu->%d\n", (unsigned long)i, mPushedAtomStats[i]);
}
}
fprintf(out, "********Pulled Atom stats***********\n");
for (const auto& pair : mPulledAtomStats) {
fprintf(out, "Atom %d->%ld, %ld, %ld\n", (int)pair.first, (long)pair.second.totalPull,
(long)pair.second.totalPullFromCache, (long)pair.second.minPullIntervalSec);
}
if (mAnomalyAlarmRegisteredStats > 0) {
fprintf(out, "********AnomalyAlarmStats stats***********\n");
fprintf(out, "Anomaly alarm registrations: %d\n", mAnomalyAlarmRegisteredStats);
}
fprintf(out,
"UID map stats: bytes=%d, snapshots=%d, changes=%d, snapshots lost=%d, changes "
"lost=%d\n",
mUidMapStats.bytes_used(), mUidMapStats.snapshots(), mUidMapStats.changes(),
mUidMapStats.dropped_snapshots(), mUidMapStats.dropped_changes());
for (const auto& error : mLoggerErrors) {
time_t error_time = error.first;
struct tm* error_tm = localtime(&error_time);
char buffer[80];
strftime(buffer, sizeof(buffer), "%Y-%m-%d %I:%M%p\n", error_tm);
fprintf(out, "Logger error %d at %s\n", error.second, buffer);
}
}
void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) {
lock_guard<std::mutex> lock(mLock);
ProtoOutputStream proto;
proto.write(FIELD_TYPE_INT32 | FIELD_ID_BEGIN_TIME, mStartTimeSec);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_END_TIME, (int32_t)getWallClockSec());
for (const auto& configStats : mIceBox) {
const int numBytes = configStats.ByteSize();
vector<char> buffer(numBytes);
configStats.SerializeToArray(&buffer[0], numBytes);
proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0],
buffer.size());
}
for (auto& pair : mConfigStats) {
auto& configStats = pair.second;
addSubStatsToConfigLocked(pair.first, configStats);
const int numBytes = configStats.ByteSize();
vector<char> buffer(numBytes);
configStats.SerializeToArray(&buffer[0], numBytes);
proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0],
buffer.size());
// reset the sub stats, the source of truth is in the individual map
// they will be repopulated when dumpStats() is called again.
configStats.clear_matcher_stats();
configStats.clear_condition_stats();
configStats.clear_metric_stats();
configStats.clear_alert_stats();
}
const size_t atomCounts = mPushedAtomStats.size();
for (size_t i = 2; i < atomCounts; i++) {
if (mPushedAtomStats[i] > 0) {
long long token =
proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_ATOM_STATS | FIELD_COUNT_REPEATED);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_TAG, (int32_t)i);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_COUNT, mPushedAtomStats[i]);
proto.end(token);
}
}
for (const auto& pair : mPulledAtomStats) {
android::os::statsd::writePullerStatsToStream(pair, &proto);
}
if (mAnomalyAlarmRegisteredStats > 0) {
long long token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_ANOMALY_ALARM_STATS);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_ANOMALY_ALARMS_REGISTERED,
mAnomalyAlarmRegisteredStats);
proto.end(token);
}
const int numBytes = mUidMapStats.ByteSize();
vector<char> buffer(numBytes);
mUidMapStats.SerializeToArray(&buffer[0], numBytes);
proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UIDMAP_STATS, &buffer[0], buffer.size());
for (const auto& error : mLoggerErrors) {
long long token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_LOGGER_ERROR_STATS |
FIELD_COUNT_REPEATED);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOGGER_STATS_TIME, error.first);
proto.write(FIELD_TYPE_INT32 | FIELD_ID_LOGGER_STATS_ERROR_CODE, error.second);
proto.end(token);
}
output->clear();
size_t bufferSize = proto.size();
output->resize(bufferSize);
size_t pos = 0;
auto it = proto.data();
while (it.readBuffer() != NULL) {
size_t toRead = it.currentToRead();
std::memcpy(&((*output)[pos]), it.readBuffer(), toRead);
pos += toRead;
it.rp()->move(toRead);
}
if (reset) {
resetInternalLocked();
}
VLOG("reset=%d, returned proto size %lu", reset, (unsigned long)bufferSize);
}
} // namespace statsd
} // namespace os
} // namespace android