1 /* 2 * Copyright (C) 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 17 #define DEBUG false // STOPSHIP if true 18 #include "Log.h" 19 #include "statslog.h" 20 21 #include <android-base/file.h> 22 #include <dirent.h> 23 #include <frameworks/base/cmds/statsd/src/active_config_list.pb.h> 24 #include "StatsLogProcessor.h" 25 #include "android-base/stringprintf.h" 26 #include "external/StatsPullerManager.h" 27 #include "guardrail/StatsdStats.h" 28 #include "metrics/CountMetricProducer.h" 29 #include "stats_log_util.h" 30 #include "stats_util.h" 31 #include "storage/StorageManager.h" 32 33 #include <log/log_event_list.h> 34 #include <utils/Errors.h> 35 #include <utils/SystemClock.h> 36 37 using namespace android; 38 using android::base::StringPrintf; 39 using android::util::FIELD_COUNT_REPEATED; 40 using android::util::FIELD_TYPE_BOOL; 41 using android::util::FIELD_TYPE_FLOAT; 42 using android::util::FIELD_TYPE_INT32; 43 using android::util::FIELD_TYPE_INT64; 44 using android::util::FIELD_TYPE_MESSAGE; 45 using android::util::FIELD_TYPE_STRING; 46 using android::util::ProtoOutputStream; 47 using std::make_unique; 48 using std::unique_ptr; 49 using std::vector; 50 51 namespace android { 52 namespace os { 53 namespace statsd { 54 55 // for ConfigMetricsReportList 56 const int FIELD_ID_CONFIG_KEY = 1; 57 const int FIELD_ID_REPORTS = 2; 58 // for ConfigKey 59 const int FIELD_ID_UID = 1; 60 const int FIELD_ID_ID = 2; 61 // for ConfigMetricsReport 62 // const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp 63 const int FIELD_ID_UID_MAP = 2; 64 const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3; 65 const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4; 66 const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5; 67 const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6; 68 const int FIELD_ID_DUMP_REPORT_REASON = 8; 69 const int FIELD_ID_STRINGS = 9; 70 71 // for ActiveConfigList 72 const int FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG = 1; 73 74 #define NS_PER_HOUR 3600 * NS_PER_SEC 75 76 #define STATS_ACTIVE_METRIC_DIR "/data/misc/stats-active-metric" 77 78 // Cool down period for writing data to disk to avoid overwriting files. 79 #define WRITE_DATA_COOL_DOWN_SEC 5 80 81 StatsLogProcessor::StatsLogProcessor(const sp<UidMap>& uidMap, 82 const sp<StatsPullerManager>& pullerManager, 83 const sp<AlarmMonitor>& anomalyAlarmMonitor, 84 const sp<AlarmMonitor>& periodicAlarmMonitor, 85 const int64_t timeBaseNs, 86 const std::function<bool(const ConfigKey&)>& sendBroadcast, 87 const std::function<bool( 88 const int&, const vector<int64_t>&)>& activateBroadcast) 89 : mUidMap(uidMap), 90 mPullerManager(pullerManager), 91 mAnomalyAlarmMonitor(anomalyAlarmMonitor), 92 mPeriodicAlarmMonitor(periodicAlarmMonitor), 93 mSendBroadcast(sendBroadcast), 94 mSendActivationBroadcast(activateBroadcast), 95 mTimeBaseNs(timeBaseNs), 96 mLargestTimestampSeen(0), 97 mLastTimestampSeen(0) { 98 mPullerManager->ForceClearPullerCache(); 99 } 100 101 StatsLogProcessor::~StatsLogProcessor() { 102 } 103 104 static void flushProtoToBuffer(ProtoOutputStream& proto, vector<uint8_t>* outData) { 105 outData->clear(); 106 outData->resize(proto.size()); 107 size_t pos = 0; 108 sp<android::util::ProtoReader> reader = proto.data(); 109 while (reader->readBuffer() != NULL) { 110 size_t toRead = reader->currentToRead(); 111 std::memcpy(&((*outData)[pos]), reader->readBuffer(), toRead); 112 pos += toRead; 113 reader->move(toRead); 114 } 115 } 116 117 void StatsLogProcessor::onAnomalyAlarmFired( 118 const int64_t& timestampNs, 119 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) { 120 std::lock_guard<std::mutex> lock(mMetricsMutex); 121 for (const auto& itr : mMetricsManagers) { 122 itr.second->onAnomalyAlarmFired(timestampNs, alarmSet); 123 } 124 } 125 void StatsLogProcessor::onPeriodicAlarmFired( 126 const int64_t& timestampNs, 127 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) { 128 129 std::lock_guard<std::mutex> lock(mMetricsMutex); 130 for (const auto& itr : mMetricsManagers) { 131 itr.second->onPeriodicAlarmFired(timestampNs, alarmSet); 132 } 133 } 134 135 void updateUid(Value* value, int hostUid) { 136 int uid = value->int_value; 137 if (uid != hostUid) { 138 value->setInt(hostUid); 139 } 140 } 141 142 void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const { 143 if (android::util::AtomsInfo::kAtomsWithAttributionChain.find(event->GetTagId()) != 144 android::util::AtomsInfo::kAtomsWithAttributionChain.end()) { 145 for (auto& value : *(event->getMutableValues())) { 146 if (value.mField.getPosAtDepth(0) > kAttributionField) { 147 break; 148 } 149 if (isAttributionUidField(value)) { 150 const int hostUid = mUidMap->getHostUidOrSelf(value.mValue.int_value); 151 updateUid(&value.mValue, hostUid); 152 } 153 } 154 } else { 155 auto it = android::util::AtomsInfo::kAtomsWithUidField.find(event->GetTagId()); 156 if (it != android::util::AtomsInfo::kAtomsWithUidField.end()) { 157 int uidField = it->second; // uidField is the field number in proto, 158 // starting from 1 159 if (uidField > 0 && (int)event->getValues().size() >= uidField && 160 (event->getValues())[uidField - 1].mValue.getType() == INT) { 161 Value& value = (*event->getMutableValues())[uidField - 1].mValue; 162 const int hostUid = mUidMap->getHostUidOrSelf(value.int_value); 163 updateUid(&value, hostUid); 164 } else { 165 ALOGE("Malformed log, uid not found. %s", event->ToString().c_str()); 166 } 167 } 168 } 169 } 170 171 void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) { 172 status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR; 173 bool is_create = event.GetBool(3, &err); 174 auto parent_uid = int(event.GetLong(1, &err2)); 175 auto isolated_uid = int(event.GetLong(2, &err3)); 176 if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) { 177 if (is_create) { 178 mUidMap->assignIsolatedUid(isolated_uid, parent_uid); 179 } else { 180 mUidMap->removeIsolatedUid(isolated_uid); 181 } 182 } else { 183 ALOGE("Failed to parse uid in the isolated uid change event."); 184 } 185 } 186 187 void StatsLogProcessor::resetConfigs() { 188 std::lock_guard<std::mutex> lock(mMetricsMutex); 189 resetConfigsLocked(getElapsedRealtimeNs()); 190 } 191 192 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) { 193 std::vector<ConfigKey> configKeys; 194 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) { 195 configKeys.push_back(it->first); 196 } 197 resetConfigsLocked(timestampNs, configKeys); 198 } 199 200 void StatsLogProcessor::OnLogEvent(LogEvent* event) { 201 std::lock_guard<std::mutex> lock(mMetricsMutex); 202 203 #ifdef VERY_VERBOSE_PRINTING 204 if (mPrintAllLogs) { 205 ALOGI("%s", event->ToString().c_str()); 206 } 207 #endif 208 const int64_t currentTimestampNs = event->GetElapsedTimestampNs(); 209 210 resetIfConfigTtlExpiredLocked(currentTimestampNs); 211 212 StatsdStats::getInstance().noteAtomLogged( 213 event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC); 214 215 // Hard-coded logic to update the isolated uid's in the uid-map. 216 // The field numbers need to be currently updated by hand with atoms.proto 217 if (event->GetTagId() == android::util::ISOLATED_UID_CHANGED) { 218 onIsolatedUidChangedEventLocked(*event); 219 } 220 221 if (mMetricsManagers.empty()) { 222 return; 223 } 224 225 int64_t curTimeSec = getElapsedRealtimeSec(); 226 if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) { 227 mPullerManager->ClearPullerCacheIfNecessary(curTimeSec * NS_PER_SEC); 228 mLastPullerCacheClearTimeSec = curTimeSec; 229 } 230 231 232 if (event->GetTagId() != android::util::ISOLATED_UID_CHANGED) { 233 // Map the isolated uid to host uid if necessary. 234 mapIsolatedUidToHostUidIfNecessaryLocked(event); 235 } 236 237 std::unordered_set<int> uidsWithActiveConfigsChanged; 238 std::unordered_map<int, std::vector<int64_t>> activeConfigsPerUid; 239 // pass the event to metrics managers. 240 for (auto& pair : mMetricsManagers) { 241 int uid = pair.first.GetUid(); 242 int64_t configId = pair.first.GetId(); 243 bool isPrevActive = pair.second->isActive(); 244 pair.second->onLogEvent(*event); 245 bool isCurActive = pair.second->isActive(); 246 // Map all active configs by uid. 247 if (isCurActive) { 248 auto activeConfigs = activeConfigsPerUid.find(uid); 249 if (activeConfigs != activeConfigsPerUid.end()) { 250 activeConfigs->second.push_back(configId); 251 } else { 252 vector<int64_t> newActiveConfigs; 253 newActiveConfigs.push_back(configId); 254 activeConfigsPerUid[uid] = newActiveConfigs; 255 } 256 } 257 // The activation state of this config changed. 258 if (isPrevActive != isCurActive) { 259 VLOG("Active status changed for uid %d", uid); 260 uidsWithActiveConfigsChanged.insert(uid); 261 StatsdStats::getInstance().noteActiveStatusChanged(pair.first, isCurActive); 262 } 263 flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second)); 264 } 265 266 for (int uid : uidsWithActiveConfigsChanged) { 267 // Send broadcast so that receivers can pull data. 268 auto lastBroadcastTime = mLastActivationBroadcastTimes.find(uid); 269 if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) { 270 if (currentTimestampNs - lastBroadcastTime->second < 271 StatsdStats::kMinActivationBroadcastPeriodNs) { 272 StatsdStats::getInstance().noteActivationBroadcastGuardrailHit(uid); 273 VLOG("StatsD would've sent an activation broadcast but the rate limit stopped us."); 274 return; 275 } 276 } 277 auto activeConfigs = activeConfigsPerUid.find(uid); 278 if (activeConfigs != activeConfigsPerUid.end()) { 279 if (mSendActivationBroadcast(uid, activeConfigs->second)) { 280 VLOG("StatsD sent activation notice for uid %d", uid); 281 mLastActivationBroadcastTimes[uid] = currentTimestampNs; 282 } 283 } else { 284 std::vector<int64_t> emptyActiveConfigs; 285 if (mSendActivationBroadcast(uid, emptyActiveConfigs)) { 286 VLOG("StatsD sent EMPTY activation notice for uid %d", uid); 287 mLastActivationBroadcastTimes[uid] = currentTimestampNs; 288 } 289 } 290 } 291 } 292 293 void StatsLogProcessor::GetActiveConfigs(const int uid, vector<int64_t>& outActiveConfigs) { 294 std::lock_guard<std::mutex> lock(mMetricsMutex); 295 GetActiveConfigsLocked(uid, outActiveConfigs); 296 } 297 298 void StatsLogProcessor::GetActiveConfigsLocked(const int uid, vector<int64_t>& outActiveConfigs) { 299 outActiveConfigs.clear(); 300 for (auto& pair : mMetricsManagers) { 301 if (pair.first.GetUid() == uid && pair.second->isActive()) { 302 outActiveConfigs.push_back(pair.first.GetId()); 303 } 304 } 305 } 306 307 void StatsLogProcessor::OnConfigUpdated(const int64_t timestampNs, const ConfigKey& key, 308 const StatsdConfig& config) { 309 std::lock_guard<std::mutex> lock(mMetricsMutex); 310 WriteDataToDiskLocked(key, timestampNs, CONFIG_UPDATED, NO_TIME_CONSTRAINTS); 311 OnConfigUpdatedLocked(timestampNs, key, config); 312 } 313 314 void StatsLogProcessor::OnConfigUpdatedLocked( 315 const int64_t timestampNs, const ConfigKey& key, const StatsdConfig& config) { 316 VLOG("Updated configuration for key %s", key.ToString().c_str()); 317 sp<MetricsManager> newMetricsManager = 318 new MetricsManager(key, config, mTimeBaseNs, timestampNs, mUidMap, mPullerManager, 319 mAnomalyAlarmMonitor, mPeriodicAlarmMonitor); 320 if (newMetricsManager->isConfigValid()) { 321 mUidMap->OnConfigUpdated(key); 322 if (newMetricsManager->shouldAddUidMapListener()) { 323 // We have to add listener after the MetricsManager is constructed because it's 324 // not safe to create wp or sp from this pointer inside its constructor. 325 mUidMap->addListener(newMetricsManager.get()); 326 } 327 newMetricsManager->refreshTtl(timestampNs); 328 mMetricsManagers[key] = newMetricsManager; 329 VLOG("StatsdConfig valid"); 330 } else { 331 // If there is any error in the config, don't use it. 332 ALOGE("StatsdConfig NOT valid"); 333 } 334 } 335 336 size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const { 337 std::lock_guard<std::mutex> lock(mMetricsMutex); 338 auto it = mMetricsManagers.find(key); 339 if (it == mMetricsManagers.end()) { 340 ALOGW("Config source %s does not exist", key.ToString().c_str()); 341 return 0; 342 } 343 return it->second->byteSize(); 344 } 345 346 void StatsLogProcessor::dumpStates(int out, bool verbose) { 347 std::lock_guard<std::mutex> lock(mMetricsMutex); 348 FILE* fout = fdopen(out, "w"); 349 if (fout == NULL) { 350 return; 351 } 352 fprintf(fout, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size()); 353 for (auto metricsManager : mMetricsManagers) { 354 metricsManager.second->dumpStates(fout, verbose); 355 } 356 357 fclose(fout); 358 } 359 360 /* 361 * onDumpReport dumps serialized ConfigMetricsReportList into proto. 362 */ 363 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs, 364 const bool include_current_partial_bucket, 365 const bool erase_data, 366 const DumpReportReason dumpReportReason, 367 const DumpLatency dumpLatency, 368 ProtoOutputStream* proto) { 369 std::lock_guard<std::mutex> lock(mMetricsMutex); 370 371 // Start of ConfigKey. 372 uint64_t configKeyToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY); 373 proto->write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid()); 374 proto->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId()); 375 proto->end(configKeyToken); 376 // End of ConfigKey. 377 378 bool keepFile = false; 379 auto it = mMetricsManagers.find(key); 380 if (it != mMetricsManagers.end() && it->second->shouldPersistLocalHistory()) { 381 keepFile = true; 382 } 383 384 // Then, check stats-data directory to see there's any file containing 385 // ConfigMetricsReport from previous shutdowns to concatenate to reports. 386 StorageManager::appendConfigMetricsReport( 387 key, proto, erase_data && !keepFile /* should remove file after appending it */, 388 dumpReportReason == ADB_DUMP /*if caller is adb*/); 389 390 if (it != mMetricsManagers.end()) { 391 // This allows another broadcast to be sent within the rate-limit period if we get close to 392 // filling the buffer again soon. 393 mLastBroadcastTimes.erase(key); 394 395 vector<uint8_t> buffer; 396 onConfigMetricsReportLocked(key, dumpTimeStampNs, include_current_partial_bucket, 397 erase_data, dumpReportReason, dumpLatency, 398 false /* is this data going to be saved on disk */, &buffer); 399 proto->write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS, 400 reinterpret_cast<char*>(buffer.data()), buffer.size()); 401 } else { 402 ALOGW("Config source %s does not exist", key.ToString().c_str()); 403 } 404 } 405 406 /* 407 * onDumpReport dumps serialized ConfigMetricsReportList into outData. 408 */ 409 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs, 410 const bool include_current_partial_bucket, 411 const bool erase_data, 412 const DumpReportReason dumpReportReason, 413 const DumpLatency dumpLatency, 414 vector<uint8_t>* outData) { 415 ProtoOutputStream proto; 416 onDumpReport(key, dumpTimeStampNs, include_current_partial_bucket, erase_data, 417 dumpReportReason, dumpLatency, &proto); 418 419 if (outData != nullptr) { 420 flushProtoToBuffer(proto, outData); 421 VLOG("output data size %zu", outData->size()); 422 } 423 424 StatsdStats::getInstance().noteMetricsReportSent(key, proto.size()); 425 } 426 427 /* 428 * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData. 429 */ 430 void StatsLogProcessor::onConfigMetricsReportLocked( 431 const ConfigKey& key, const int64_t dumpTimeStampNs, 432 const bool include_current_partial_bucket, const bool erase_data, 433 const DumpReportReason dumpReportReason, const DumpLatency dumpLatency, 434 const bool dataSavedOnDisk, vector<uint8_t>* buffer) { 435 // We already checked whether key exists in mMetricsManagers in 436 // WriteDataToDisk. 437 auto it = mMetricsManagers.find(key); 438 if (it == mMetricsManagers.end()) { 439 return; 440 } 441 int64_t lastReportTimeNs = it->second->getLastReportTimeNs(); 442 int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs(); 443 444 std::set<string> str_set; 445 446 ProtoOutputStream tempProto; 447 // First, fill in ConfigMetricsReport using current data on memory, which 448 // starts from filling in StatsLogReport's. 449 it->second->onDumpReport(dumpTimeStampNs, include_current_partial_bucket, erase_data, 450 dumpLatency, &str_set, &tempProto); 451 452 // Fill in UidMap if there is at least one metric to report. 453 // This skips the uid map if it's an empty config. 454 if (it->second->getNumMetrics() > 0) { 455 uint64_t uidMapToken = tempProto.start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP); 456 mUidMap->appendUidMap( 457 dumpTimeStampNs, key, it->second->hashStringInReport() ? &str_set : nullptr, 458 it->second->versionStringsInReport(), it->second->installerInReport(), &tempProto); 459 tempProto.end(uidMapToken); 460 } 461 462 // Fill in the timestamps. 463 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS, 464 (long long)lastReportTimeNs); 465 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS, 466 (long long)dumpTimeStampNs); 467 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS, 468 (long long)lastReportWallClockNs); 469 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS, 470 (long long)getWallClockNs()); 471 // Dump report reason 472 tempProto.write(FIELD_TYPE_INT32 | FIELD_ID_DUMP_REPORT_REASON, dumpReportReason); 473 474 for (const auto& str : str_set) { 475 tempProto.write(FIELD_TYPE_STRING | FIELD_COUNT_REPEATED | FIELD_ID_STRINGS, str); 476 } 477 478 flushProtoToBuffer(tempProto, buffer); 479 480 // save buffer to disk if needed 481 if (erase_data && !dataSavedOnDisk && it->second->shouldPersistLocalHistory()) { 482 VLOG("save history to disk"); 483 string file_name = StorageManager::getDataHistoryFileName((long)getWallClockSec(), 484 key.GetUid(), key.GetId()); 485 StorageManager::writeFile(file_name.c_str(), buffer->data(), buffer->size()); 486 } 487 } 488 489 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs, 490 const std::vector<ConfigKey>& configs) { 491 for (const auto& key : configs) { 492 StatsdConfig config; 493 if (StorageManager::readConfigFromDisk(key, &config)) { 494 OnConfigUpdatedLocked(timestampNs, key, config); 495 StatsdStats::getInstance().noteConfigReset(key); 496 } else { 497 ALOGE("Failed to read backup config from disk for : %s", key.ToString().c_str()); 498 auto it = mMetricsManagers.find(key); 499 if (it != mMetricsManagers.end()) { 500 it->second->refreshTtl(timestampNs); 501 } 502 } 503 } 504 } 505 506 void StatsLogProcessor::resetIfConfigTtlExpiredLocked(const int64_t timestampNs) { 507 std::vector<ConfigKey> configKeysTtlExpired; 508 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) { 509 if (it->second != nullptr && !it->second->isInTtl(timestampNs)) { 510 configKeysTtlExpired.push_back(it->first); 511 } 512 } 513 if (configKeysTtlExpired.size() > 0) { 514 WriteDataToDiskLocked(CONFIG_RESET, NO_TIME_CONSTRAINTS); 515 resetConfigsLocked(timestampNs, configKeysTtlExpired); 516 } 517 } 518 519 void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) { 520 std::lock_guard<std::mutex> lock(mMetricsMutex); 521 auto it = mMetricsManagers.find(key); 522 if (it != mMetricsManagers.end()) { 523 WriteDataToDiskLocked(key, getElapsedRealtimeNs(), CONFIG_REMOVED, 524 NO_TIME_CONSTRAINTS); 525 mMetricsManagers.erase(it); 526 mUidMap->OnConfigRemoved(key); 527 } 528 StatsdStats::getInstance().noteConfigRemoved(key); 529 530 mLastBroadcastTimes.erase(key); 531 532 int uid = key.GetUid(); 533 bool lastConfigForUid = true; 534 for (auto it : mMetricsManagers) { 535 if (it.first.GetUid() == uid) { 536 lastConfigForUid = false; 537 break; 538 } 539 } 540 if (lastConfigForUid) { 541 mLastActivationBroadcastTimes.erase(uid); 542 } 543 544 if (mMetricsManagers.empty()) { 545 mPullerManager->ForceClearPullerCache(); 546 } 547 } 548 549 void StatsLogProcessor::flushIfNecessaryLocked( 550 int64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) { 551 auto lastCheckTime = mLastByteSizeTimes.find(key); 552 if (lastCheckTime != mLastByteSizeTimes.end()) { 553 if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) { 554 return; 555 } 556 } 557 558 // We suspect that the byteSize() computation is expensive, so we set a rate limit. 559 size_t totalBytes = metricsManager.byteSize(); 560 mLastByteSizeTimes[key] = timestampNs; 561 bool requestDump = false; 562 if (totalBytes > 563 StatsdStats::kMaxMetricsBytesPerConfig) { // Too late. We need to start clearing data. 564 metricsManager.dropData(timestampNs); 565 StatsdStats::getInstance().noteDataDropped(key, totalBytes); 566 VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str()); 567 } else if ((totalBytes > StatsdStats::kBytesPerConfigTriggerGetData) || 568 (mOnDiskDataConfigs.find(key) != mOnDiskDataConfigs.end())) { 569 // Request to send a broadcast if: 570 // 1. in memory data > threshold OR 571 // 2. config has old data report on disk. 572 requestDump = true; 573 } 574 575 if (requestDump) { 576 // Send broadcast so that receivers can pull data. 577 auto lastBroadcastTime = mLastBroadcastTimes.find(key); 578 if (lastBroadcastTime != mLastBroadcastTimes.end()) { 579 if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) { 580 VLOG("StatsD would've sent a broadcast but the rate limit stopped us."); 581 return; 582 } 583 } 584 if (mSendBroadcast(key)) { 585 mOnDiskDataConfigs.erase(key); 586 VLOG("StatsD triggered data fetch for %s", key.ToString().c_str()); 587 mLastBroadcastTimes[key] = timestampNs; 588 StatsdStats::getInstance().noteBroadcastSent(key); 589 } 590 } 591 } 592 593 void StatsLogProcessor::WriteDataToDiskLocked(const ConfigKey& key, 594 const int64_t timestampNs, 595 const DumpReportReason dumpReportReason, 596 const DumpLatency dumpLatency) { 597 if (mMetricsManagers.find(key) == mMetricsManagers.end() || 598 !mMetricsManagers.find(key)->second->shouldWriteToDisk()) { 599 return; 600 } 601 vector<uint8_t> buffer; 602 onConfigMetricsReportLocked(key, timestampNs, true /* include_current_partial_bucket*/, 603 true /* erase_data */, dumpReportReason, dumpLatency, true, 604 &buffer); 605 string file_name = 606 StorageManager::getDataFileName((long)getWallClockSec(), key.GetUid(), key.GetId()); 607 StorageManager::writeFile(file_name.c_str(), buffer.data(), buffer.size()); 608 609 // We were able to write the ConfigMetricsReport to disk, so we should trigger collection ASAP. 610 mOnDiskDataConfigs.insert(key); 611 } 612 613 void StatsLogProcessor::SaveActiveConfigsToDisk(int64_t currentTimeNs) { 614 std::lock_guard<std::mutex> lock(mMetricsMutex); 615 const int64_t timeNs = getElapsedRealtimeNs(); 616 // Do not write to disk if we already have in the last few seconds. 617 if (static_cast<unsigned long long> (timeNs) < 618 mLastActiveMetricsWriteNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) { 619 ALOGI("Statsd skipping writing active metrics to disk. Already wrote data in last %d seconds", 620 WRITE_DATA_COOL_DOWN_SEC); 621 return; 622 } 623 mLastActiveMetricsWriteNs = timeNs; 624 625 ProtoOutputStream proto; 626 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, DEVICE_SHUTDOWN, &proto); 627 628 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR); 629 StorageManager::deleteFile(file_name.c_str()); 630 android::base::unique_fd fd( 631 open(file_name.c_str(), O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR)); 632 if (fd == -1) { 633 ALOGE("Attempt to write %s but failed", file_name.c_str()); 634 return; 635 } 636 proto.flush(fd.get()); 637 } 638 639 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStream( 640 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) { 641 std::lock_guard<std::mutex> lock(mMetricsMutex); 642 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, reason, proto); 643 } 644 645 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStreamLocked( 646 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) { 647 for (const auto& pair : mMetricsManagers) { 648 const sp<MetricsManager>& metricsManager = pair.second; 649 uint64_t configToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | 650 FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG); 651 metricsManager->writeActiveConfigToProtoOutputStream(currentTimeNs, reason, proto); 652 proto->end(configToken); 653 } 654 } 655 void StatsLogProcessor::LoadActiveConfigsFromDisk() { 656 std::lock_guard<std::mutex> lock(mMetricsMutex); 657 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR); 658 int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC); 659 if (-1 == fd) { 660 VLOG("Attempt to read %s but failed", file_name.c_str()); 661 StorageManager::deleteFile(file_name.c_str()); 662 return; 663 } 664 string content; 665 if (!android::base::ReadFdToString(fd, &content)) { 666 ALOGE("Attempt to read %s but failed", file_name.c_str()); 667 close(fd); 668 StorageManager::deleteFile(file_name.c_str()); 669 return; 670 } 671 672 close(fd); 673 674 ActiveConfigList activeConfigList; 675 if (!activeConfigList.ParseFromString(content)) { 676 ALOGE("Attempt to read %s but failed; failed to load active configs", file_name.c_str()); 677 StorageManager::deleteFile(file_name.c_str()); 678 return; 679 } 680 // Passing in mTimeBaseNs only works as long as we only load from disk is when statsd starts. 681 SetConfigsActiveStateLocked(activeConfigList, mTimeBaseNs); 682 StorageManager::deleteFile(file_name.c_str()); 683 } 684 685 void StatsLogProcessor::SetConfigsActiveState(const ActiveConfigList& activeConfigList, 686 int64_t currentTimeNs) { 687 std::lock_guard<std::mutex> lock(mMetricsMutex); 688 SetConfigsActiveStateLocked(activeConfigList, currentTimeNs); 689 } 690 691 void StatsLogProcessor::SetConfigsActiveStateLocked(const ActiveConfigList& activeConfigList, 692 int64_t currentTimeNs) { 693 for (int i = 0; i < activeConfigList.config_size(); i++) { 694 const auto& config = activeConfigList.config(i); 695 ConfigKey key(config.uid(), config.id()); 696 auto it = mMetricsManagers.find(key); 697 if (it == mMetricsManagers.end()) { 698 ALOGE("No config found for config %s", key.ToString().c_str()); 699 continue; 700 } 701 VLOG("Setting active config %s", key.ToString().c_str()); 702 it->second->loadActiveConfig(config, currentTimeNs); 703 } 704 VLOG("Successfully loaded %d active configs.", activeConfigList.config_size()); 705 } 706 707 void StatsLogProcessor::WriteDataToDiskLocked(const DumpReportReason dumpReportReason, 708 const DumpLatency dumpLatency) { 709 const int64_t timeNs = getElapsedRealtimeNs(); 710 // Do not write to disk if we already have in the last few seconds. 711 // This is to avoid overwriting files that would have the same name if we 712 // write twice in the same second. 713 if (static_cast<unsigned long long> (timeNs) < 714 mLastWriteTimeNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) { 715 ALOGI("Statsd skipping writing data to disk. Already wrote data in last %d seconds", 716 WRITE_DATA_COOL_DOWN_SEC); 717 return; 718 } 719 mLastWriteTimeNs = timeNs; 720 for (auto& pair : mMetricsManagers) { 721 WriteDataToDiskLocked(pair.first, timeNs, dumpReportReason, dumpLatency); 722 } 723 } 724 725 void StatsLogProcessor::WriteDataToDisk(const DumpReportReason dumpReportReason, 726 const DumpLatency dumpLatency) { 727 std::lock_guard<std::mutex> lock(mMetricsMutex); 728 WriteDataToDiskLocked(dumpReportReason, dumpLatency); 729 } 730 731 void StatsLogProcessor::informPullAlarmFired(const int64_t timestampNs) { 732 std::lock_guard<std::mutex> lock(mMetricsMutex); 733 mPullerManager->OnAlarmFired(timestampNs); 734 } 735 736 int64_t StatsLogProcessor::getLastReportTimeNs(const ConfigKey& key) { 737 auto it = mMetricsManagers.find(key); 738 if (it == mMetricsManagers.end()) { 739 return 0; 740 } else { 741 return it->second->getLastReportTimeNs(); 742 } 743 } 744 745 void StatsLogProcessor::noteOnDiskData(const ConfigKey& key) { 746 std::lock_guard<std::mutex> lock(mMetricsMutex); 747 mOnDiskDataConfigs.insert(key); 748 } 749 750 } // namespace statsd 751 } // namespace os 752 } // namespace android 753