StatsdStats.cpp revision c136f45aee2c193e954c107f35109ccc8b1146b3
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 "statslog.h" 23 24namespace android { 25namespace os { 26namespace statsd { 27 28using android::util::FIELD_COUNT_REPEATED; 29using android::util::FIELD_TYPE_BOOL; 30using android::util::FIELD_TYPE_FLOAT; 31using android::util::FIELD_TYPE_INT32; 32using android::util::FIELD_TYPE_INT64; 33using android::util::FIELD_TYPE_MESSAGE; 34using android::util::FIELD_TYPE_STRING; 35using android::util::ProtoOutputStream; 36using std::lock_guard; 37using std::map; 38using std::string; 39using std::vector; 40 41const int FIELD_ID_BEGIN_TIME = 1; 42const int FIELD_ID_END_TIME = 2; 43const int FIELD_ID_CONFIG_STATS = 3; 44const int FIELD_ID_MATCHER_STATS = 4; 45const int FIELD_ID_CONDITION_STATS = 5; 46const int FIELD_ID_METRIC_STATS = 6; 47const int FIELD_ID_ATOM_STATS = 7; 48const int FIELD_ID_UIDMAP_STATS = 8; 49 50const int FIELD_ID_MATCHER_STATS_NAME = 1; 51const int FIELD_ID_MATCHER_STATS_COUNT = 2; 52 53const int FIELD_ID_CONDITION_STATS_NAME = 1; 54const int FIELD_ID_CONDITION_STATS_COUNT = 2; 55 56const int FIELD_ID_METRIC_STATS_NAME = 1; 57const int FIELD_ID_METRIC_STATS_COUNT = 2; 58 59const int FIELD_ID_ATOM_STATS_TAG = 1; 60const int FIELD_ID_ATOM_STATS_COUNT = 2; 61 62// TODO: add stats for pulled atoms. 63StatsdStats::StatsdStats() { 64 mPushedAtomStats.resize(android::util::kMaxPushedAtomId + 1); 65 mStartTimeSec = time(nullptr); 66} 67 68StatsdStats& StatsdStats::getInstance() { 69 static StatsdStats statsInstance; 70 return statsInstance; 71} 72 73void StatsdStats::noteConfigReceived(const ConfigKey& key, int metricsCount, int conditionsCount, 74 int matchersCount, int alertsCount, bool isValid) { 75 lock_guard<std::mutex> lock(mLock); 76 int32_t nowTimeSec = time(nullptr); 77 78 // If there is an existing config for the same key, icebox the old config. 79 noteConfigRemovedInternalLocked(key); 80 81 StatsdStatsReport_ConfigStats configStats; 82 configStats.set_uid(key.GetUid()); 83 configStats.set_name(key.GetName()); 84 configStats.set_creation_time_sec(nowTimeSec); 85 configStats.set_metric_count(metricsCount); 86 configStats.set_condition_count(conditionsCount); 87 configStats.set_matcher_count(matchersCount); 88 configStats.set_alert_count(alertsCount); 89 configStats.set_is_valid(isValid); 90 91 if (isValid) { 92 mConfigStats[key] = configStats; 93 } else { 94 configStats.set_deletion_time_sec(nowTimeSec); 95 mIceBox.push_back(configStats); 96 } 97} 98 99void StatsdStats::noteConfigRemovedInternalLocked(const ConfigKey& key) { 100 auto it = mConfigStats.find(key); 101 if (it != mConfigStats.end()) { 102 int32_t nowTimeSec = time(nullptr); 103 it->second.set_deletion_time_sec(nowTimeSec); 104 // Add condition stats, metrics stats, matcher stats 105 addSubStatsToConfig(key, it->second); 106 // Remove them after they are added to the config stats. 107 mMatcherStats.erase(key); 108 mMetricsStats.erase(key); 109 mConditionStats.erase(key); 110 mIceBox.push_back(it->second); 111 mConfigStats.erase(it); 112 } 113} 114 115void StatsdStats::noteConfigRemoved(const ConfigKey& key) { 116 lock_guard<std::mutex> lock(mLock); 117 noteConfigRemovedInternalLocked(key); 118} 119 120void StatsdStats::noteBroadcastSent(const ConfigKey& key) { 121 noteBroadcastSent(key, time(nullptr)); 122} 123 124void StatsdStats::noteBroadcastSent(const ConfigKey& key, int32_t timeSec) { 125 lock_guard<std::mutex> lock(mLock); 126 auto it = mConfigStats.find(key); 127 if (it == mConfigStats.end()) { 128 ALOGE("Config key %s not found!", key.ToString().c_str()); 129 return; 130 } 131 if (it->second.broadcast_sent_time_sec_size() >= kMaxTimestampCount) { 132 auto timestampList = it->second.mutable_broadcast_sent_time_sec(); 133 // This is O(N) operation. It shouldn't happen often, and N is only 20. 134 timestampList->erase(timestampList->begin()); 135 } 136 it->second.add_broadcast_sent_time_sec(timeSec); 137} 138 139void StatsdStats::noteDataDropped(const ConfigKey& key) { 140 noteDataDropped(key, time(nullptr)); 141} 142 143void StatsdStats::noteDataDropped(const ConfigKey& key, int32_t timeSec) { 144 lock_guard<std::mutex> lock(mLock); 145 auto it = mConfigStats.find(key); 146 if (it == mConfigStats.end()) { 147 ALOGE("Config key %s not found!", key.ToString().c_str()); 148 return; 149 } 150 if (it->second.data_drop_time_sec_size() >= kMaxTimestampCount) { 151 auto timestampList = it->second.mutable_data_drop_time_sec(); 152 // This is O(N) operation. It shouldn't happen often, and N is only 20. 153 timestampList->erase(timestampList->begin()); 154 } 155 it->second.add_data_drop_time_sec(timeSec); 156} 157 158void StatsdStats::noteMetricsReportSent(const ConfigKey& key) { 159 noteMetricsReportSent(key, time(nullptr)); 160} 161 162void StatsdStats::noteMetricsReportSent(const ConfigKey& key, int32_t timeSec) { 163 lock_guard<std::mutex> lock(mLock); 164 auto it = mConfigStats.find(key); 165 if (it == mConfigStats.end()) { 166 ALOGE("Config key %s not found!", key.ToString().c_str()); 167 return; 168 } 169 if (it->second.dump_report_time_sec_size() >= kMaxTimestampCount) { 170 auto timestampList = it->second.mutable_dump_report_time_sec(); 171 // This is O(N) operation. It shouldn't happen often, and N is only 20. 172 timestampList->erase(timestampList->begin()); 173 } 174 it->second.add_dump_report_time_sec(timeSec); 175} 176 177void StatsdStats::noteUidMapDropped(int snapshots, int deltas) { 178 lock_guard<std::mutex> lock(mLock); 179 mUidMapStats.set_dropped_snapshots(mUidMapStats.dropped_snapshots() + snapshots); 180 mUidMapStats.set_dropped_changes(mUidMapStats.dropped_changes() + deltas); 181} 182 183void StatsdStats::setUidMapSnapshots(int snapshots) { 184 lock_guard<std::mutex> lock(mLock); 185 mUidMapStats.set_snapshots(snapshots); 186} 187 188void StatsdStats::setUidMapChanges(int changes) { 189 lock_guard<std::mutex> lock(mLock); 190 mUidMapStats.set_changes(changes); 191} 192 193void StatsdStats::setCurrentUidMapMemory(int bytes) { 194 lock_guard<std::mutex> lock(mLock); 195 mUidMapStats.set_bytes_used(bytes); 196} 197 198void StatsdStats::noteConditionDimensionSize(const ConfigKey& key, const string& name, int size) { 199 lock_guard<std::mutex> lock(mLock); 200 // if name doesn't exist before, it will create the key with count 0. 201 auto& conditionSizeMap = mConditionStats[key]; 202 if (size > conditionSizeMap[name]) { 203 conditionSizeMap[name] = size; 204 } 205} 206 207void StatsdStats::noteMetricDimensionSize(const ConfigKey& key, const string& name, int size) { 208 lock_guard<std::mutex> lock(mLock); 209 // if name doesn't exist before, it will create the key with count 0. 210 auto& metricsDimensionMap = mMetricsStats[key]; 211 if (size > metricsDimensionMap[name]) { 212 metricsDimensionMap[name] = size; 213 } 214} 215 216void StatsdStats::noteMatcherMatched(const ConfigKey& key, const string& name) { 217 lock_guard<std::mutex> lock(mLock); 218 auto& matcherStats = mMatcherStats[key]; 219 matcherStats[name]++; 220} 221 222void StatsdStats::noteAtomLogged(int atomId, int32_t timeSec) { 223 lock_guard<std::mutex> lock(mLock); 224 225 if (timeSec < mStartTimeSec) { 226 return; 227 } 228 229 if (atomId > android::util::kMaxPushedAtomId) { 230 ALOGW("not interested in atom %d", atomId); 231 return; 232 } 233 234 mPushedAtomStats[atomId]++; 235} 236 237void StatsdStats::reset() { 238 lock_guard<std::mutex> lock(mLock); 239 resetInternalLocked(); 240} 241 242void StatsdStats::resetInternalLocked() { 243 // Reset the historical data, but keep the active ConfigStats 244 mStartTimeSec = time(nullptr); 245 mIceBox.clear(); 246 mConditionStats.clear(); 247 mMetricsStats.clear(); 248 std::fill(mPushedAtomStats.begin(), mPushedAtomStats.end(), 0); 249 mMatcherStats.clear(); 250 for (auto& config : mConfigStats) { 251 config.second.clear_broadcast_sent_time_sec(); 252 config.second.clear_data_drop_time_sec(); 253 config.second.clear_dump_report_time_sec(); 254 config.second.clear_matcher_stats(); 255 config.second.clear_condition_stats(); 256 config.second.clear_metric_stats(); 257 } 258} 259 260void StatsdStats::addSubStatsToConfig(const ConfigKey& key, 261 StatsdStatsReport_ConfigStats& configStats) { 262 // Add matcher stats 263 if (mMatcherStats.find(key) != mMatcherStats.end()) { 264 const auto& matcherStats = mMatcherStats[key]; 265 for (const auto& stats : matcherStats) { 266 auto output = configStats.add_matcher_stats(); 267 output->set_name(stats.first); 268 output->set_matched_times(stats.second); 269 VLOG("matcher %s matched %d times", stats.first.c_str(), stats.second); 270 } 271 } 272 // Add condition stats 273 if (mConditionStats.find(key) != mConditionStats.end()) { 274 const auto& conditionStats = mConditionStats[key]; 275 for (const auto& stats : conditionStats) { 276 auto output = configStats.add_condition_stats(); 277 output->set_name(stats.first); 278 output->set_max_tuple_counts(stats.second); 279 VLOG("condition %s max output tuple size %d", stats.first.c_str(), stats.second); 280 } 281 } 282 // Add metrics stats 283 if (mMetricsStats.find(key) != mMetricsStats.end()) { 284 const auto& conditionStats = mMetricsStats[key]; 285 for (const auto& stats : conditionStats) { 286 auto output = configStats.add_metric_stats(); 287 output->set_name(stats.first); 288 output->set_max_tuple_counts(stats.second); 289 VLOG("metrics %s max output tuple size %d", stats.first.c_str(), stats.second); 290 } 291 } 292} 293 294void StatsdStats::dumpStats(std::vector<uint8_t>* output, bool reset) { 295 lock_guard<std::mutex> lock(mLock); 296 297 if (DEBUG) { 298 time_t t = mStartTimeSec; 299 struct tm* tm = localtime(&t); 300 char timeBuffer[80]; 301 strftime(timeBuffer, sizeof(timeBuffer), "%Y-%m-%d %I:%M%p", tm); 302 VLOG("=================StatsdStats dump begins===================="); 303 VLOG("Stats collection start second: %s", timeBuffer); 304 } 305 ProtoOutputStream proto; 306 proto.write(FIELD_TYPE_INT32 | FIELD_ID_BEGIN_TIME, mStartTimeSec); 307 proto.write(FIELD_TYPE_INT32 | FIELD_ID_END_TIME, (int32_t)time(nullptr)); 308 309 VLOG("%lu Config in icebox: ", (unsigned long)mIceBox.size()); 310 for (const auto& configStats : mIceBox) { 311 const int numBytes = configStats.ByteSize(); 312 vector<char> buffer(numBytes); 313 configStats.SerializeToArray(&buffer[0], numBytes); 314 proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0], 315 buffer.size()); 316 317 // surround the whole block with DEBUG, so that compiler can strip out the code 318 // in production. 319 if (DEBUG) { 320 VLOG("*****ICEBOX*****"); 321 VLOG("Config {%d-%s}: creation=%d, deletion=%d, #metric=%d, #condition=%d, " 322 "#matcher=%d, #alert=%d, #valid=%d", 323 configStats.uid(), configStats.name().c_str(), configStats.creation_time_sec(), 324 configStats.deletion_time_sec(), configStats.metric_count(), 325 configStats.condition_count(), configStats.matcher_count(), 326 configStats.alert_count(), configStats.is_valid()); 327 328 for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) { 329 VLOG("\tbroadcast time: %d", broadcastTime); 330 } 331 332 for (const auto& dataDropTime : configStats.data_drop_time_sec()) { 333 VLOG("\tdata drop time: %d", dataDropTime); 334 } 335 } 336 } 337 338 for (auto& pair : mConfigStats) { 339 auto& configStats = pair.second; 340 if (DEBUG) { 341 VLOG("********Active Configs***********"); 342 VLOG("Config {%d-%s}: creation=%d, deletion=%d, #metric=%d, #condition=%d, " 343 "#matcher=%d, #alert=%d, #valid=%d", 344 configStats.uid(), configStats.name().c_str(), configStats.creation_time_sec(), 345 configStats.deletion_time_sec(), configStats.metric_count(), 346 configStats.condition_count(), configStats.matcher_count(), 347 configStats.alert_count(), configStats.is_valid()); 348 for (const auto& broadcastTime : configStats.broadcast_sent_time_sec()) { 349 VLOG("\tbroadcast time: %d", broadcastTime); 350 } 351 352 for (const auto& dataDropTime : configStats.data_drop_time_sec()) { 353 VLOG("\tdata drop time: %d", dataDropTime); 354 } 355 356 for (const auto& dumpTime : configStats.dump_report_time_sec()) { 357 VLOG("\tdump report time: %d", dumpTime); 358 } 359 } 360 361 addSubStatsToConfig(pair.first, configStats); 362 363 const int numBytes = configStats.ByteSize(); 364 vector<char> buffer(numBytes); 365 configStats.SerializeToArray(&buffer[0], numBytes); 366 proto.write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_CONFIG_STATS, &buffer[0], 367 buffer.size()); 368 // reset the sub stats, the source of truth is in the individual map 369 // they will be repopulated when dumpStats() is called again. 370 configStats.clear_matcher_stats(); 371 configStats.clear_condition_stats(); 372 configStats.clear_metric_stats(); 373 } 374 375 VLOG("********Atom stats***********"); 376 const size_t atomCounts = mPushedAtomStats.size(); 377 for (size_t i = 2; i < atomCounts; i++) { 378 if (mPushedAtomStats[i] > 0) { 379 long long token = 380 proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_ATOM_STATS | FIELD_COUNT_REPEATED); 381 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_TAG, (int32_t)i); 382 proto.write(FIELD_TYPE_INT32 | FIELD_ID_ATOM_STATS_COUNT, mPushedAtomStats[i]); 383 proto.end(token); 384 385 VLOG("Atom %lu->%d\n", (unsigned long)i, mPushedAtomStats[i]); 386 } 387 } 388 389 const int numBytes = mUidMapStats.ByteSize(); 390 vector<char> buffer(numBytes); 391 mUidMapStats.SerializeToArray(&buffer[0], numBytes); 392 proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UIDMAP_STATS, &buffer[0], buffer.size()); 393 VLOG("UID map stats: bytes=%d, snapshots=%d, changes=%d, snapshots lost=%d, changes " 394 "lost=%d", 395 mUidMapStats.bytes_used(), mUidMapStats.snapshots(), mUidMapStats.changes(), 396 mUidMapStats.dropped_snapshots(), mUidMapStats.dropped_changes()); 397 398 output->clear(); 399 size_t bufferSize = proto.size(); 400 output->resize(bufferSize); 401 402 size_t pos = 0; 403 auto it = proto.data(); 404 while (it.readBuffer() != NULL) { 405 size_t toRead = it.currentToRead(); 406 std::memcpy(&((*output)[pos]), it.readBuffer(), toRead); 407 pos += toRead; 408 it.rp()->move(toRead); 409 } 410 411 if (reset) { 412 resetInternalLocked(); 413 } 414 415 VLOG("reset=%d, returned proto size %lu", reset, (unsigned long)bufferSize); 416 VLOG("=================StatsdStats dump ends===================="); 417} 418 419} // namespace statsd 420} // namespace os 421} // namespace android