StatsdStats.cpp revision b038b709566c191164bd23539175df8aadeb2f94
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::noteConfigReceived(const ConfigKey& key, int metricsCount, int conditionsCount, 89 int matchersCount, int alertsCount, bool isValid) { 90 lock_guard<std::mutex> lock(mLock); 91 int32_t nowTimeSec = time(nullptr); 92 93 // If there is an existing config for the same key, icebox the old config. 94 noteConfigRemovedInternalLocked(key); 95 96 StatsdStatsReport_ConfigStats configStats; 97 configStats.set_uid(key.GetUid()); 98 configStats.set_id(key.GetId()); 99 configStats.set_creation_time_sec(nowTimeSec); 100 configStats.set_metric_count(metricsCount); 101 configStats.set_condition_count(conditionsCount); 102 configStats.set_matcher_count(matchersCount); 103 configStats.set_alert_count(alertsCount); 104 configStats.set_is_valid(isValid); 105 106 if (isValid) { 107 mConfigStats[key] = configStats; 108 } else { 109 configStats.set_deletion_time_sec(nowTimeSec); 110 mIceBox.push_back(configStats); 111 } 112} 113 114void StatsdStats::noteConfigRemovedInternalLocked(const ConfigKey& key) { 115 auto it = mConfigStats.find(key); 116 if (it != mConfigStats.end()) { 117 int32_t nowTimeSec = time(nullptr); 118 it->second.set_deletion_time_sec(nowTimeSec); 119 // Add condition stats, metrics stats, matcher stats, alert stats 120 addSubStatsToConfigLocked(key, it->second); 121 // Remove them after they are added to the config stats. 122 mMatcherStats.erase(key); 123 mMetricsStats.erase(key); 124 mAlertStats.erase(key); 125 mConditionStats.erase(key); 126 mIceBox.push_back(it->second); 127 mConfigStats.erase(it); 128 } 129} 130 131void StatsdStats::noteConfigRemoved(const ConfigKey& key) { 132 lock_guard<std::mutex> lock(mLock); 133 noteConfigRemovedInternalLocked(key); 134} 135 136void StatsdStats::noteBroadcastSent(const ConfigKey& key) { 137 noteBroadcastSent(key, time(nullptr)); 138} 139 140void StatsdStats::noteBroadcastSent(const ConfigKey& key, int32_t timeSec) { 141 lock_guard<std::mutex> lock(mLock); 142 auto it = mConfigStats.find(key); 143 if (it == mConfigStats.end()) { 144 ALOGE("Config key %s not found!", key.ToString().c_str()); 145 return; 146 } 147 if (it->second.broadcast_sent_time_sec_size() >= kMaxTimestampCount) { 148 auto timestampList = it->second.mutable_broadcast_sent_time_sec(); 149 // This is O(N) operation. It shouldn't happen often, and N is only 20. 150 timestampList->erase(timestampList->begin()); 151 } 152 it->second.add_broadcast_sent_time_sec(timeSec); 153} 154 155void StatsdStats::noteDataDropped(const ConfigKey& key) { 156 noteDataDropped(key, time(nullptr)); 157} 158 159void StatsdStats::noteDataDropped(const ConfigKey& key, int32_t timeSec) { 160 lock_guard<std::mutex> lock(mLock); 161 auto it = mConfigStats.find(key); 162 if (it == mConfigStats.end()) { 163 ALOGE("Config key %s not found!", key.ToString().c_str()); 164 return; 165 } 166 if (it->second.data_drop_time_sec_size() >= kMaxTimestampCount) { 167 auto timestampList = it->second.mutable_data_drop_time_sec(); 168 // This is O(N) operation. It shouldn't happen often, and N is only 20. 169 timestampList->erase(timestampList->begin()); 170 } 171 it->second.add_data_drop_time_sec(timeSec); 172} 173 174void StatsdStats::noteMetricsReportSent(const ConfigKey& key) { 175 noteMetricsReportSent(key, time(nullptr)); 176} 177 178void StatsdStats::noteMetricsReportSent(const ConfigKey& key, int32_t timeSec) { 179 lock_guard<std::mutex> lock(mLock); 180 auto it = mConfigStats.find(key); 181 if (it == mConfigStats.end()) { 182 ALOGE("Config key %s not found!", key.ToString().c_str()); 183 return; 184 } 185 if (it->second.dump_report_time_sec_size() >= kMaxTimestampCount) { 186 auto timestampList = it->second.mutable_dump_report_time_sec(); 187 // This is O(N) operation. It shouldn't happen often, and N is only 20. 188 timestampList->erase(timestampList->begin()); 189 } 190 it->second.add_dump_report_time_sec(timeSec); 191} 192 193void StatsdStats::noteUidMapDropped(int snapshots, int deltas) { 194 lock_guard<std::mutex> lock(mLock); 195 mUidMapStats.set_dropped_snapshots(mUidMapStats.dropped_snapshots() + snapshots); 196 mUidMapStats.set_dropped_changes(mUidMapStats.dropped_changes() + deltas); 197} 198 199void StatsdStats::setUidMapSnapshots(int snapshots) { 200 lock_guard<std::mutex> lock(mLock); 201 mUidMapStats.set_snapshots(snapshots); 202} 203 204void StatsdStats::setUidMapChanges(int changes) { 205 lock_guard<std::mutex> lock(mLock); 206 mUidMapStats.set_changes(changes); 207} 208 209void StatsdStats::setCurrentUidMapMemory(int bytes) { 210 lock_guard<std::mutex> lock(mLock); 211 mUidMapStats.set_bytes_used(bytes); 212} 213 214void StatsdStats::noteConditionDimensionSize(const ConfigKey& key, const int64_t& id, int size) { 215 lock_guard<std::mutex> lock(mLock); 216 // if name doesn't exist before, it will create the key with count 0. 217 auto& conditionSizeMap = mConditionStats[key]; 218 if (size > conditionSizeMap[id]) { 219 conditionSizeMap[id] = size; 220 } 221} 222 223void StatsdStats::noteMetricDimensionSize(const ConfigKey& key, const int64_t& id, int size) { 224 lock_guard<std::mutex> lock(mLock); 225 // if name doesn't exist before, it will create the key with count 0. 226 auto& metricsDimensionMap = mMetricsStats[key]; 227 if (size > metricsDimensionMap[id]) { 228 metricsDimensionMap[id] = size; 229 } 230} 231 232void StatsdStats::noteMatcherMatched(const ConfigKey& key, const int64_t& id) { 233 lock_guard<std::mutex> lock(mLock); 234 auto& matcherStats = mMatcherStats[key]; 235 matcherStats[id]++; 236} 237 238void StatsdStats::noteAnomalyDeclared(const ConfigKey& key, const int64_t& id) { 239 lock_guard<std::mutex> lock(mLock); 240 auto& alertStats = mAlertStats[key]; 241 alertStats[id]++; 242} 243 244void StatsdStats::noteRegisteredAnomalyAlarmChanged() { 245 lock_guard<std::mutex> lock(mLock); 246 mAnomalyAlarmRegisteredStats++; 247} 248 249void StatsdStats::updateMinPullIntervalSec(int pullAtomId, long intervalSec) { 250 lock_guard<std::mutex> lock(mLock); 251 mPulledAtomStats[pullAtomId].minPullIntervalSec = intervalSec; 252} 253 254void StatsdStats::notePull(int pullAtomId) { 255 lock_guard<std::mutex> lock(mLock); 256 mPulledAtomStats[pullAtomId].totalPull++; 257} 258 259void StatsdStats::notePullFromCache(int pullAtomId) { 260 lock_guard<std::mutex> lock(mLock); 261 mPulledAtomStats[pullAtomId].totalPullFromCache++; 262} 263 264void StatsdStats::noteAtomLogged(int atomId, int32_t timeSec) { 265 lock_guard<std::mutex> lock(mLock); 266 267 if (timeSec < mStartTimeSec) { 268 return; 269 } 270 271 if (atomId > android::util::kMaxPushedAtomId) { 272 ALOGW("not interested in atom %d", atomId); 273 return; 274 } 275 276 mPushedAtomStats[atomId]++; 277} 278 279void StatsdStats::reset() { 280 lock_guard<std::mutex> lock(mLock); 281 resetInternalLocked(); 282} 283 284void StatsdStats::resetInternalLocked() { 285 // Reset the historical data, but keep the active ConfigStats 286 mStartTimeSec = time(nullptr); 287 mIceBox.clear(); 288 mConditionStats.clear(); 289 mMetricsStats.clear(); 290 std::fill(mPushedAtomStats.begin(), mPushedAtomStats.end(), 0); 291 mAlertStats.clear(); 292 mAnomalyAlarmRegisteredStats = 0; 293 mMatcherStats.clear(); 294 for (auto& config : mConfigStats) { 295 config.second.clear_broadcast_sent_time_sec(); 296 config.second.clear_data_drop_time_sec(); 297 config.second.clear_dump_report_time_sec(); 298 config.second.clear_matcher_stats(); 299 config.second.clear_condition_stats(); 300 config.second.clear_metric_stats(); 301 config.second.clear_alert_stats(); 302 } 303} 304 305void StatsdStats::addSubStatsToConfigLocked(const ConfigKey& key, 306 StatsdStatsReport_ConfigStats& configStats) { 307 // Add matcher stats 308 if (mMatcherStats.find(key) != mMatcherStats.end()) { 309 const auto& matcherStats = mMatcherStats[key]; 310 for (const auto& stats : matcherStats) { 311 auto output = configStats.add_matcher_stats(); 312 output->set_id(stats.first); 313 output->set_matched_times(stats.second); 314 VLOG("matcher %lld matched %d times", 315 (long long)stats.first, stats.second); 316 } 317 } 318 // Add condition stats 319 if (mConditionStats.find(key) != mConditionStats.end()) { 320 const auto& conditionStats = mConditionStats[key]; 321 for (const auto& stats : conditionStats) { 322 auto output = configStats.add_condition_stats(); 323 output->set_id(stats.first); 324 output->set_max_tuple_counts(stats.second); 325 VLOG("condition %lld max output tuple size %d", 326 (long long)stats.first, stats.second); 327 } 328 } 329 // Add metrics stats 330 if (mMetricsStats.find(key) != mMetricsStats.end()) { 331 const auto& conditionStats = mMetricsStats[key]; 332 for (const auto& stats : conditionStats) { 333 auto output = configStats.add_metric_stats(); 334 output->set_id(stats.first); 335 output->set_max_tuple_counts(stats.second); 336 VLOG("metrics %lld max output tuple size %d", 337 (long long)stats.first, stats.second); 338 } 339 } 340 // Add anomaly detection alert stats 341 if (mAlertStats.find(key) != mAlertStats.end()) { 342 const auto& alertStats = mAlertStats[key]; 343 for (const auto& stats : alertStats) { 344 auto output = configStats.add_alert_stats(); 345 output->set_id(stats.first); 346 output->set_alerted_times(stats.second); 347 VLOG("alert %lld declared %d times", (long long)stats.first, stats.second); 348 } 349 } 350} 351 352void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) { 353 lock_guard<std::mutex> lock(mLock); 354 355 if (DEBUG) { 356 time_t t = mStartTimeSec; 357 struct tm* tm = localtime(&t); 358 char timeBuffer[80]; 359 strftime(timeBuffer, sizeof(timeBuffer), "%Y-%m-%d %I:%M%p", tm); 360 VLOG("=================StatsdStats dump begins===================="); 361 VLOG("Stats collection start second: %s", timeBuffer); 362 } 363 ProtoOutputStream proto; 364 proto.write(FIELD_TYPE_INT32 | FIELD_ID_BEGIN_TIME, mStartTimeSec); 365 proto.write(FIELD_TYPE_INT32 | FIELD_ID_END_TIME, (int32_t)time(nullptr)); 366 367 VLOG("%lu Config in icebox: ", (unsigned long)mIceBox.size()); 368 for (const auto& configStats : mIceBox) { 369 const int numBytes = configStats.ByteSize(); 370 vector<char> buffer(numBytes); 371 configStats.SerializeToArray(&buffer[0], numBytes); 372 proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0], 373 buffer.size()); 374 375 // surround the whole block with DEBUG, so that compiler can strip out the code 376 // in production. 377 if (DEBUG) { 378 VLOG("*****ICEBOX*****"); 379 VLOG("Config {%d-%lld}: creation=%d, deletion=%d, #metric=%d, #condition=%d, " 380 "#matcher=%d, #alert=%d, #valid=%d", 381 configStats.uid(), (long long)configStats.id(), configStats.creation_time_sec(), 382 configStats.deletion_time_sec(), configStats.metric_count(), 383 configStats.condition_count(), configStats.matcher_count(), 384 configStats.alert_count(), configStats.is_valid()); 385 386 for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) { 387 VLOG("\tbroadcast time: %d", broadcastTime); 388 } 389 390 for (const auto& dataDropTime : configStats.data_drop_time_sec()) { 391 VLOG("\tdata drop time: %d", dataDropTime); 392 } 393 } 394 } 395 396 for (auto& pair : mConfigStats) { 397 auto& configStats = pair.second; 398 if (DEBUG) { 399 VLOG("********Active Configs***********"); 400 VLOG("Config {%d-%lld}: creation=%d, deletion=%d, #metric=%d, #condition=%d, " 401 "#matcher=%d, #alert=%d, #valid=%d", 402 configStats.uid(), (long long)configStats.id(), configStats.creation_time_sec(), 403 configStats.deletion_time_sec(), configStats.metric_count(), 404 configStats.condition_count(), configStats.matcher_count(), 405 configStats.alert_count(), configStats.is_valid()); 406 for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) { 407 VLOG("\tbroadcast time: %d", broadcastTime); 408 } 409 410 for (const auto& dataDropTime : configStats.data_drop_time_sec()) { 411 VLOG("\tdata drop time: %d", dataDropTime); 412 } 413 414 for (const auto& dumpTime : configStats.dump_report_time_sec()) { 415 VLOG("\tdump report time: %d", dumpTime); 416 } 417 } 418 419 addSubStatsToConfigLocked(pair.first, configStats); 420 421 const int numBytes = configStats.ByteSize(); 422 vector<char> buffer(numBytes); 423 configStats.SerializeToArray(&buffer[0], numBytes); 424 proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0], 425 buffer.size()); 426 // reset the sub stats, the source of truth is in the individual map 427 // they will be repopulated when dumpStats() is called again. 428 configStats.clear_matcher_stats(); 429 configStats.clear_condition_stats(); 430 configStats.clear_metric_stats(); 431 configStats.clear_alert_stats(); 432 } 433 434 VLOG("********Pushed Atom stats***********"); 435 const size_t atomCounts = mPushedAtomStats.size(); 436 for (size_t i = 2; i < atomCounts; i++) { 437 if (mPushedAtomStats[i] > 0) { 438 long long token = 439 proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_ATOM_STATS | FIELD_COUNT_REPEATED); 440 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_TAG, (int32_t)i); 441 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_COUNT, mPushedAtomStats[i]); 442 proto.end(token); 443 444 VLOG("Atom %lu->%d\n", (unsigned long)i, mPushedAtomStats[i]); 445 } 446 } 447 448 VLOG("********Pulled Atom stats***********"); 449 for (const auto& pair : mPulledAtomStats) { 450 android::os::statsd::writePullerStatsToStream(pair, &proto); 451 VLOG("Atom %d->%ld, %ld, %ld\n", (int) pair.first, (long) pair.second.totalPull, (long) pair.second.totalPullFromCache, (long) pair.second.minPullIntervalSec); 452 } 453 454 if (mAnomalyAlarmRegisteredStats > 0) { 455 VLOG("********AnomalyAlarmStats stats***********"); 456 long long token = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_ANOMALY_ALARM_STATS); 457 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ANOMALY_ALARMS_REGISTERED, 458 mAnomalyAlarmRegisteredStats); 459 proto.end(token); 460 VLOG("Anomaly alarm registrations: %d", mAnomalyAlarmRegisteredStats); 461 } 462 463 const int numBytes = mUidMapStats.ByteSize(); 464 vector<char> buffer(numBytes); 465 mUidMapStats.SerializeToArray(&buffer[0], numBytes); 466 proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UIDMAP_STATS, &buffer[0], buffer.size()); 467 VLOG("UID map stats: bytes=%d, snapshots=%d, changes=%d, snapshots lost=%d, changes " 468 "lost=%d", 469 mUidMapStats.bytes_used(), mUidMapStats.snapshots(), mUidMapStats.changes(), 470 mUidMapStats.dropped_snapshots(), mUidMapStats.dropped_changes()); 471 472 output->clear(); 473 size_t bufferSize = proto.size(); 474 output->resize(bufferSize); 475 476 size_t pos = 0; 477 auto it = proto.data(); 478 while (it.readBuffer() != NULL) { 479 size_t toRead = it.currentToRead(); 480 std::memcpy(&((*output)[pos]), it.readBuffer(), toRead); 481 pos += toRead; 482 it.rp()->move(toRead); 483 } 484 485 if (reset) { 486 resetInternalLocked(); 487 } 488 489 VLOG("reset=%d, returned proto size %lu", reset, (unsigned long)bufferSize); 490 VLOG("=================StatsdStats dump ends===================="); 491} 492 493} // namespace statsd 494} // namespace os 495} // namespace android