StatsdStats.cpp revision f5acabe9466af3571a4318852cdb26856e5ba100
1/* 2 * Copyright 2017, The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16#define DEBUG true // STOPSHIP if true 17#include "Log.h" 18 19#include "StatsdStats.h" 20 21#include <android/util/ProtoOutputStream.h> 22#include "../stats_log_util.h" 23#include "statslog.h" 24 25namespace android { 26namespace os { 27namespace statsd { 28 29using android::util::FIELD_COUNT_REPEATED; 30using android::util::FIELD_TYPE_BOOL; 31using android::util::FIELD_TYPE_FLOAT; 32using android::util::FIELD_TYPE_INT32; 33using android::util::FIELD_TYPE_INT64; 34using android::util::FIELD_TYPE_MESSAGE; 35using android::util::FIELD_TYPE_STRING; 36using android::util::ProtoOutputStream; 37using std::lock_guard; 38using std::map; 39using std::string; 40using std::vector; 41 42const int FIELD_ID_BEGIN_TIME = 1; 43const int FIELD_ID_END_TIME = 2; 44const int FIELD_ID_CONFIG_STATS = 3; 45const int FIELD_ID_ATOM_STATS = 7; 46const int FIELD_ID_UIDMAP_STATS = 8; 47const int FIELD_ID_ANOMALY_ALARM_STATS = 9; 48 49const int FIELD_ID_MATCHER_STATS_NAME = 1; 50const int FIELD_ID_MATCHER_STATS_COUNT = 2; 51 52const int FIELD_ID_CONDITION_STATS_NAME = 1; 53const int FIELD_ID_CONDITION_STATS_COUNT = 2; 54 55const int FIELD_ID_METRIC_STATS_NAME = 1; 56const int FIELD_ID_METRIC_STATS_COUNT = 2; 57 58const int FIELD_ID_ATOM_STATS_TAG = 1; 59const int FIELD_ID_ATOM_STATS_COUNT = 2; 60 61const int FIELD_ID_ANOMALY_ALARMS_REGISTERED = 1; 62 63std::map<int, long> StatsdStats::kPullerCooldownMap = { 64 {android::util::KERNEL_WAKELOCK, 1}, 65 {android::util::WIFI_BYTES_TRANSFER, 1}, 66 {android::util::MOBILE_BYTES_TRANSFER, 1}, 67 {android::util::WIFI_BYTES_TRANSFER_BY_FG_BG, 1}, 68 {android::util::MOBILE_BYTES_TRANSFER_BY_FG_BG, 1}, 69 {android::util::PLATFORM_SLEEP_STATE, 1}, 70 {android::util::SLEEP_STATE_VOTER, 1}, 71 {android::util::SUBSYSTEM_SLEEP_STATE, 1}, 72 {android::util::CPU_TIME_PER_FREQ, 1}, 73 {android::util::CPU_TIME_PER_UID, 1}, 74 {android::util::CPU_TIME_PER_UID_FREQ, 1}, 75}; 76 77// TODO: add stats for pulled atoms. 78StatsdStats::StatsdStats() { 79 mPushedAtomStats.resize(android::util::kMaxPushedAtomId + 1); 80 mStartTimeSec = time(nullptr); 81} 82 83StatsdStats& StatsdStats::getInstance() { 84 static StatsdStats statsInstance; 85 return statsInstance; 86} 87 88void StatsdStats::addToIceBoxLocked(const StatsdStatsReport_ConfigStats& stats) { 89 // The size of mIceBox grows strictly by one at a time. It won't be > kMaxIceBoxSize. 90 if (mIceBox.size() == kMaxIceBoxSize) { 91 mIceBox.pop_front(); 92 } 93 mIceBox.push_back(stats); 94} 95 96void StatsdStats::noteConfigReceived(const ConfigKey& key, int metricsCount, int conditionsCount, 97 int matchersCount, int alertsCount, bool isValid) { 98 lock_guard<std::mutex> lock(mLock); 99 int32_t nowTimeSec = time(nullptr); 100 101 // If there is an existing config for the same key, icebox the old config. 102 noteConfigRemovedInternalLocked(key); 103 104 StatsdStatsReport_ConfigStats configStats; 105 configStats.set_uid(key.GetUid()); 106 configStats.set_id(key.GetId()); 107 configStats.set_creation_time_sec(nowTimeSec); 108 configStats.set_metric_count(metricsCount); 109 configStats.set_condition_count(conditionsCount); 110 configStats.set_matcher_count(matchersCount); 111 configStats.set_alert_count(alertsCount); 112 configStats.set_is_valid(isValid); 113 114 if (isValid) { 115 mConfigStats[key] = configStats; 116 } else { 117 configStats.set_deletion_time_sec(nowTimeSec); 118 addToIceBoxLocked(configStats); 119 } 120} 121 122void StatsdStats::noteConfigRemovedInternalLocked(const ConfigKey& key) { 123 auto it = mConfigStats.find(key); 124 if (it != mConfigStats.end()) { 125 int32_t nowTimeSec = time(nullptr); 126 it->second.set_deletion_time_sec(nowTimeSec); 127 // Add condition stats, metrics stats, matcher stats, alert stats 128 addSubStatsToConfigLocked(key, it->second); 129 // Remove them after they are added to the config stats. 130 mMatcherStats.erase(key); 131 mMetricsStats.erase(key); 132 mAlertStats.erase(key); 133 mConditionStats.erase(key); 134 addToIceBoxLocked(it->second); 135 mConfigStats.erase(it); 136 } 137} 138 139void StatsdStats::noteConfigRemoved(const ConfigKey& key) { 140 lock_guard<std::mutex> lock(mLock); 141 noteConfigRemovedInternalLocked(key); 142} 143 144void StatsdStats::noteBroadcastSent(const ConfigKey& key) { 145 noteBroadcastSent(key, time(nullptr)); 146} 147 148void StatsdStats::noteBroadcastSent(const ConfigKey& key, int32_t timeSec) { 149 lock_guard<std::mutex> lock(mLock); 150 auto it = mConfigStats.find(key); 151 if (it == mConfigStats.end()) { 152 ALOGE("Config key %s not found!", key.ToString().c_str()); 153 return; 154 } 155 if (it->second.broadcast_sent_time_sec_size() >= kMaxTimestampCount) { 156 auto timestampList = it->second.mutable_broadcast_sent_time_sec(); 157 // This is O(N) operation. It shouldn't happen often, and N is only 20. 158 timestampList->erase(timestampList->begin()); 159 } 160 it->second.add_broadcast_sent_time_sec(timeSec); 161} 162 163void StatsdStats::noteDataDropped(const ConfigKey& key) { 164 noteDataDropped(key, time(nullptr)); 165} 166 167void StatsdStats::noteDataDropped(const ConfigKey& key, int32_t timeSec) { 168 lock_guard<std::mutex> lock(mLock); 169 auto it = mConfigStats.find(key); 170 if (it == mConfigStats.end()) { 171 ALOGE("Config key %s not found!", key.ToString().c_str()); 172 return; 173 } 174 if (it->second.data_drop_time_sec_size() >= kMaxTimestampCount) { 175 auto timestampList = it->second.mutable_data_drop_time_sec(); 176 // This is O(N) operation. It shouldn't happen often, and N is only 20. 177 timestampList->erase(timestampList->begin()); 178 } 179 it->second.add_data_drop_time_sec(timeSec); 180} 181 182void StatsdStats::noteMetricsReportSent(const ConfigKey& key) { 183 noteMetricsReportSent(key, time(nullptr)); 184} 185 186void StatsdStats::noteMetricsReportSent(const ConfigKey& key, int32_t timeSec) { 187 lock_guard<std::mutex> lock(mLock); 188 auto it = mConfigStats.find(key); 189 if (it == mConfigStats.end()) { 190 ALOGE("Config key %s not found!", key.ToString().c_str()); 191 return; 192 } 193 if (it->second.dump_report_time_sec_size() >= kMaxTimestampCount) { 194 auto timestampList = it->second.mutable_dump_report_time_sec(); 195 // This is O(N) operation. It shouldn't happen often, and N is only 20. 196 timestampList->erase(timestampList->begin()); 197 } 198 it->second.add_dump_report_time_sec(timeSec); 199} 200 201void StatsdStats::noteUidMapDropped(int snapshots, int deltas) { 202 lock_guard<std::mutex> lock(mLock); 203 mUidMapStats.set_dropped_snapshots(mUidMapStats.dropped_snapshots() + snapshots); 204 mUidMapStats.set_dropped_changes(mUidMapStats.dropped_changes() + deltas); 205} 206 207void StatsdStats::setUidMapSnapshots(int snapshots) { 208 lock_guard<std::mutex> lock(mLock); 209 mUidMapStats.set_snapshots(snapshots); 210} 211 212void StatsdStats::setUidMapChanges(int changes) { 213 lock_guard<std::mutex> lock(mLock); 214 mUidMapStats.set_changes(changes); 215} 216 217void StatsdStats::setCurrentUidMapMemory(int bytes) { 218 lock_guard<std::mutex> lock(mLock); 219 mUidMapStats.set_bytes_used(bytes); 220} 221 222void StatsdStats::noteConditionDimensionSize(const ConfigKey& key, const int64_t& id, int size) { 223 lock_guard<std::mutex> lock(mLock); 224 // if name doesn't exist before, it will create the key with count 0. 225 auto& conditionSizeMap = mConditionStats[key]; 226 if (size > conditionSizeMap[id]) { 227 conditionSizeMap[id] = size; 228 } 229} 230 231void StatsdStats::noteMetricDimensionSize(const ConfigKey& key, const int64_t& id, int size) { 232 lock_guard<std::mutex> lock(mLock); 233 // if name doesn't exist before, it will create the key with count 0. 234 auto& metricsDimensionMap = mMetricsStats[key]; 235 if (size > metricsDimensionMap[id]) { 236 metricsDimensionMap[id] = size; 237 } 238} 239 240void StatsdStats::noteMatcherMatched(const ConfigKey& key, const int64_t& id) { 241 lock_guard<std::mutex> lock(mLock); 242 auto& matcherStats = mMatcherStats[key]; 243 matcherStats[id]++; 244} 245 246void StatsdStats::noteAnomalyDeclared(const ConfigKey& key, const int64_t& id) { 247 lock_guard<std::mutex> lock(mLock); 248 auto& alertStats = mAlertStats[key]; 249 alertStats[id]++; 250} 251 252void StatsdStats::noteRegisteredAnomalyAlarmChanged() { 253 lock_guard<std::mutex> lock(mLock); 254 mAnomalyAlarmRegisteredStats++; 255} 256 257void StatsdStats::updateMinPullIntervalSec(int pullAtomId, long intervalSec) { 258 lock_guard<std::mutex> lock(mLock); 259 mPulledAtomStats[pullAtomId].minPullIntervalSec = intervalSec; 260} 261 262void StatsdStats::notePull(int pullAtomId) { 263 lock_guard<std::mutex> lock(mLock); 264 mPulledAtomStats[pullAtomId].totalPull++; 265} 266 267void StatsdStats::notePullFromCache(int pullAtomId) { 268 lock_guard<std::mutex> lock(mLock); 269 mPulledAtomStats[pullAtomId].totalPullFromCache++; 270} 271 272void StatsdStats::noteAtomLogged(int atomId, int32_t timeSec) { 273 lock_guard<std::mutex> lock(mLock); 274 275 if (timeSec < mStartTimeSec) { 276 return; 277 } 278 279 if (atomId > android::util::kMaxPushedAtomId) { 280 ALOGW("not interested in atom %d", atomId); 281 return; 282 } 283 284 mPushedAtomStats[atomId]++; 285} 286 287void StatsdStats::reset() { 288 lock_guard<std::mutex> lock(mLock); 289 resetInternalLocked(); 290} 291 292void StatsdStats::resetInternalLocked() { 293 // Reset the historical data, but keep the active ConfigStats 294 mStartTimeSec = time(nullptr); 295 mIceBox.clear(); 296 mConditionStats.clear(); 297 mMetricsStats.clear(); 298 std::fill(mPushedAtomStats.begin(), mPushedAtomStats.end(), 0); 299 mAlertStats.clear(); 300 mAnomalyAlarmRegisteredStats = 0; 301 mMatcherStats.clear(); 302 for (auto& config : mConfigStats) { 303 config.second.clear_broadcast_sent_time_sec(); 304 config.second.clear_data_drop_time_sec(); 305 config.second.clear_dump_report_time_sec(); 306 config.second.clear_matcher_stats(); 307 config.second.clear_condition_stats(); 308 config.second.clear_metric_stats(); 309 config.second.clear_alert_stats(); 310 } 311} 312 313void StatsdStats::addSubStatsToConfigLocked(const ConfigKey& key, 314 StatsdStatsReport_ConfigStats& configStats) { 315 // Add matcher stats 316 if (mMatcherStats.find(key) != mMatcherStats.end()) { 317 const auto& matcherStats = mMatcherStats[key]; 318 for (const auto& stats : matcherStats) { 319 auto output = configStats.add_matcher_stats(); 320 output->set_id(stats.first); 321 output->set_matched_times(stats.second); 322 VLOG("matcher %lld matched %d times", 323 (long long)stats.first, stats.second); 324 } 325 } 326 // Add condition stats 327 if (mConditionStats.find(key) != mConditionStats.end()) { 328 const auto& conditionStats = mConditionStats[key]; 329 for (const auto& stats : conditionStats) { 330 auto output = configStats.add_condition_stats(); 331 output->set_id(stats.first); 332 output->set_max_tuple_counts(stats.second); 333 VLOG("condition %lld max output tuple size %d", 334 (long long)stats.first, stats.second); 335 } 336 } 337 // Add metrics stats 338 if (mMetricsStats.find(key) != mMetricsStats.end()) { 339 const auto& conditionStats = mMetricsStats[key]; 340 for (const auto& stats : conditionStats) { 341 auto output = configStats.add_metric_stats(); 342 output->set_id(stats.first); 343 output->set_max_tuple_counts(stats.second); 344 VLOG("metrics %lld max output tuple size %d", 345 (long long)stats.first, stats.second); 346 } 347 } 348 // Add anomaly detection alert stats 349 if (mAlertStats.find(key) != mAlertStats.end()) { 350 const auto& alertStats = mAlertStats[key]; 351 for (const auto& stats : alertStats) { 352 auto output = configStats.add_alert_stats(); 353 output->set_id(stats.first); 354 output->set_alerted_times(stats.second); 355 VLOG("alert %lld declared %d times", (long long)stats.first, stats.second); 356 } 357 } 358} 359 360void StatsdStats::dumpStats(FILE* out) const { 361 lock_guard<std::mutex> lock(mLock); 362 time_t t = mStartTimeSec; 363 struct tm* tm = localtime(&t); 364 char timeBuffer[80]; 365 strftime(timeBuffer, sizeof(timeBuffer), "%Y-%m-%d %I:%M%p\n", tm); 366 fprintf(out, "Stats collection start second: %s\n", timeBuffer); 367 fprintf(out, "%lu Config in icebox: \n", (unsigned long)mIceBox.size()); 368 for (const auto& configStats : mIceBox) { 369 fprintf(out, 370 "Config {%d-%lld}: creation=%d, deletion=%d, #metric=%d, #condition=%d, " 371 "#matcher=%d, #alert=%d, valid=%d\n", 372 configStats.uid(), (long long)configStats.id(), configStats.creation_time_sec(), 373 configStats.deletion_time_sec(), configStats.metric_count(), 374 configStats.condition_count(), configStats.matcher_count(), 375 configStats.alert_count(), configStats.is_valid()); 376 377 for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) { 378 fprintf(out, "\tbroadcast time: %d\n", broadcastTime); 379 } 380 381 for (const auto& dataDropTime : configStats.data_drop_time_sec()) { 382 fprintf(out, "\tdata drop time: %d\n", dataDropTime); 383 } 384 } 385 fprintf(out, "%lu Active Configs\n", (unsigned long)mConfigStats.size()); 386 for (auto& pair : mConfigStats) { 387 auto& key = pair.first; 388 auto& configStats = pair.second; 389 390 fprintf(out, 391 "Config {%d-%lld}: creation=%d, deletion=%d, #metric=%d, #condition=%d, " 392 "#matcher=%d, #alert=%d, valid=%d\n", 393 configStats.uid(), (long long)configStats.id(), configStats.creation_time_sec(), 394 configStats.deletion_time_sec(), configStats.metric_count(), 395 configStats.condition_count(), configStats.matcher_count(), 396 configStats.alert_count(), configStats.is_valid()); 397 for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) { 398 fprintf(out, "\tbroadcast time: %d\n", broadcastTime); 399 } 400 401 for (const auto& dataDropTime : configStats.data_drop_time_sec()) { 402 fprintf(out, "\tdata drop time: %d\n", dataDropTime); 403 } 404 405 for (const auto& dumpTime : configStats.dump_report_time_sec()) { 406 fprintf(out, "\tdump report time: %d\n", dumpTime); 407 } 408 409 // Add matcher stats 410 auto matcherIt = mMatcherStats.find(key); 411 if (matcherIt != mMatcherStats.end()) { 412 const auto& matcherStats = matcherIt->second; 413 for (const auto& stats : matcherStats) { 414 fprintf(out, "matcher %lld matched %d times\n", (long long)stats.first, 415 stats.second); 416 } 417 } 418 // Add condition stats 419 auto conditionIt = mConditionStats.find(key); 420 if (conditionIt != mConditionStats.end()) { 421 const auto& conditionStats = conditionIt->second; 422 for (const auto& stats : conditionStats) { 423 fprintf(out, "condition %lld max output tuple size %d\n", (long long)stats.first, 424 stats.second); 425 } 426 } 427 // Add metrics stats 428 auto metricIt = mMetricsStats.find(key); 429 if (metricIt != mMetricsStats.end()) { 430 const auto& conditionStats = metricIt->second; 431 for (const auto& stats : conditionStats) { 432 fprintf(out, "metrics %lld max output tuple size %d\n", (long long)stats.first, 433 stats.second); 434 } 435 } 436 // Add anomaly detection alert stats 437 auto alertIt = mAlertStats.find(key); 438 if (alertIt != mAlertStats.end()) { 439 const auto& alertStats = alertIt->second; 440 for (const auto& stats : alertStats) { 441 fprintf(out, "alert %lld declared %d times\n", (long long)stats.first, 442 stats.second); 443 } 444 } 445 } 446 fprintf(out, "********Pushed Atom stats***********\n"); 447 const size_t atomCounts = mPushedAtomStats.size(); 448 for (size_t i = 2; i < atomCounts; i++) { 449 if (mPushedAtomStats[i] > 0) { 450 fprintf(out, "Atom %lu->%d\n", (unsigned long)i, mPushedAtomStats[i]); 451 } 452 } 453 454 fprintf(out, "********Pulled Atom stats***********\n"); 455 for (const auto& pair : mPulledAtomStats) { 456 fprintf(out, "Atom %d->%ld, %ld, %ld\n", (int)pair.first, (long)pair.second.totalPull, 457 (long)pair.second.totalPullFromCache, (long)pair.second.minPullIntervalSec); 458 } 459 460 if (mAnomalyAlarmRegisteredStats > 0) { 461 fprintf(out, "********AnomalyAlarmStats stats***********\n"); 462 fprintf(out, "Anomaly alarm registrations: %d\n", mAnomalyAlarmRegisteredStats); 463 } 464 465 fprintf(out, 466 "UID map stats: bytes=%d, snapshots=%d, changes=%d, snapshots lost=%d, changes " 467 "lost=%d\n", 468 mUidMapStats.bytes_used(), mUidMapStats.snapshots(), mUidMapStats.changes(), 469 mUidMapStats.dropped_snapshots(), mUidMapStats.dropped_changes()); 470} 471 472void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) { 473 lock_guard<std::mutex> lock(mLock); 474 475 ProtoOutputStream proto; 476 proto.write(FIELD_TYPE_INT32 | FIELD_ID_BEGIN_TIME, mStartTimeSec); 477 proto.write(FIELD_TYPE_INT32 | FIELD_ID_END_TIME, (int32_t)time(nullptr)); 478 479 for (const auto& configStats : mIceBox) { 480 const int numBytes = configStats.ByteSize(); 481 vector<char> buffer(numBytes); 482 configStats.SerializeToArray(&buffer[0], numBytes); 483 proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0], 484 buffer.size()); 485 } 486 487 for (auto& pair : mConfigStats) { 488 auto& configStats = pair.second; 489 addSubStatsToConfigLocked(pair.first, configStats); 490 491 const int numBytes = configStats.ByteSize(); 492 vector<char> buffer(numBytes); 493 configStats.SerializeToArray(&buffer[0], numBytes); 494 proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0], 495 buffer.size()); 496 // reset the sub stats, the source of truth is in the individual map 497 // they will be repopulated when dumpStats() is called again. 498 configStats.clear_matcher_stats(); 499 configStats.clear_condition_stats(); 500 configStats.clear_metric_stats(); 501 configStats.clear_alert_stats(); 502 } 503 504 const size_t atomCounts = mPushedAtomStats.size(); 505 for (size_t i = 2; i < atomCounts; i++) { 506 if (mPushedAtomStats[i] > 0) { 507 long long token = 508 proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_ATOM_STATS | FIELD_COUNT_REPEATED); 509 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_TAG, (int32_t)i); 510 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_COUNT, mPushedAtomStats[i]); 511 proto.end(token); 512 } 513 } 514 515 for (const auto& pair : mPulledAtomStats) { 516 android::os::statsd::writePullerStatsToStream(pair, &proto); 517 } 518 519 if (mAnomalyAlarmRegisteredStats > 0) { 520 long long token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_ANOMALY_ALARM_STATS); 521 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ANOMALY_ALARMS_REGISTERED, 522 mAnomalyAlarmRegisteredStats); 523 proto.end(token); 524 } 525 526 const int numBytes = mUidMapStats.ByteSize(); 527 vector<char> buffer(numBytes); 528 mUidMapStats.SerializeToArray(&buffer[0], numBytes); 529 proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UIDMAP_STATS, &buffer[0], buffer.size()); 530 531 output->clear(); 532 size_t bufferSize = proto.size(); 533 output->resize(bufferSize); 534 535 size_t pos = 0; 536 auto it = proto.data(); 537 while (it.readBuffer() != NULL) { 538 size_t toRead = it.currentToRead(); 539 std::memcpy(&((*output)[pos]), it.readBuffer(), toRead); 540 pos += toRead; 541 it.rp()->move(toRead); 542 } 543 544 if (reset) { 545 resetInternalLocked(); 546 } 547 548 VLOG("reset=%d, returned proto size %lu", reset, (unsigned long)bufferSize); 549} 550 551} // namespace statsd 552} // namespace os 553} // namespace android