StatsLogProcessor.cpp revision e51af37475a758d5d6ec024d79d9d2b3a7358f85
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 true // STOPSHIP if true 18#include "Log.h" 19#include "statslog.h" 20 21#include <android-base/file.h> 22#include <dirent.h> 23#include "StatsLogProcessor.h" 24#include "stats_log_util.h" 25#include "android-base/stringprintf.h" 26#include "guardrail/StatsdStats.h" 27#include "metrics/CountMetricProducer.h" 28#include "external/StatsPullerManager.h" 29#include "stats_util.h" 30#include "storage/StorageManager.h" 31 32#include <log/log_event_list.h> 33#include <utils/Errors.h> 34#include <utils/SystemClock.h> 35 36using namespace android; 37using android::base::StringPrintf; 38using android::util::FIELD_COUNT_REPEATED; 39using android::util::FIELD_TYPE_BOOL; 40using android::util::FIELD_TYPE_FLOAT; 41using android::util::FIELD_TYPE_INT32; 42using android::util::FIELD_TYPE_INT64; 43using android::util::FIELD_TYPE_MESSAGE; 44using android::util::FIELD_TYPE_STRING; 45using android::util::ProtoOutputStream; 46using std::make_unique; 47using std::unique_ptr; 48using std::vector; 49 50namespace android { 51namespace os { 52namespace statsd { 53 54// for ConfigMetricsReportList 55const int FIELD_ID_CONFIG_KEY = 1; 56const int FIELD_ID_REPORTS = 2; 57// for ConfigKey 58const int FIELD_ID_UID = 1; 59const int FIELD_ID_ID = 2; 60// for ConfigMetricsReport 61// const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp 62const int FIELD_ID_UID_MAP = 2; 63const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3; 64const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4; 65const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5; 66const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6; 67 68 69#define STATS_DATA_DIR "/data/misc/stats-data" 70 71StatsLogProcessor::StatsLogProcessor(const sp<UidMap>& uidMap, 72 const sp<AlarmMonitor>& anomalyAlarmMonitor, 73 const sp<AlarmMonitor>& periodicAlarmMonitor, 74 const long timeBaseSec, 75 const std::function<void(const ConfigKey&)>& sendBroadcast) 76 : mUidMap(uidMap), 77 mAnomalyAlarmMonitor(anomalyAlarmMonitor), 78 mPeriodicAlarmMonitor(periodicAlarmMonitor), 79 mSendBroadcast(sendBroadcast), 80 mTimeBaseSec(timeBaseSec), 81 mLastLogTimestamp(0) { 82 StatsPullerManager statsPullerManager; 83 statsPullerManager.SetTimeBaseSec(mTimeBaseSec); 84} 85 86StatsLogProcessor::~StatsLogProcessor() { 87} 88 89void StatsLogProcessor::onAnomalyAlarmFired( 90 const uint64_t timestampNs, 91 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) { 92 std::lock_guard<std::mutex> lock(mMetricsMutex); 93 for (const auto& itr : mMetricsManagers) { 94 itr.second->onAnomalyAlarmFired(timestampNs, alarmSet); 95 } 96} 97void StatsLogProcessor::onPeriodicAlarmFired( 98 const uint64_t timestampNs, 99 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) { 100 101 std::lock_guard<std::mutex> lock(mMetricsMutex); 102 for (const auto& itr : mMetricsManagers) { 103 itr.second->onPeriodicAlarmFired(timestampNs, alarmSet); 104 } 105} 106 107void updateUid(Value* value, int hostUid) { 108 int uid = value->int_value; 109 if (uid != hostUid) { 110 value->setInt(hostUid); 111 } 112} 113 114void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const { 115 if (android::util::AtomsInfo::kAtomsWithAttributionChain.find(event->GetTagId()) != 116 android::util::AtomsInfo::kAtomsWithAttributionChain.end()) { 117 for (auto& value : *(event->getMutableValues())) { 118 if (value.mField.getPosAtDepth(0) > kAttributionField) { 119 break; 120 } 121 if (isAttributionUidField(value)) { 122 const int hostUid = mUidMap->getHostUidOrSelf(value.mValue.int_value); 123 updateUid(&value.mValue, hostUid); 124 } 125 } 126 } else { 127 auto it = android::util::AtomsInfo::kAtomsWithUidField.find(event->GetTagId()); 128 if (it != android::util::AtomsInfo::kAtomsWithUidField.end()) { 129 int uidField = it->second; // uidField is the field number in proto, 130 // starting from 1 131 if (uidField > 0 && (int)event->getValues().size() >= uidField && 132 (event->getValues())[uidField - 1].mValue.getType() == INT) { 133 Value& value = (*event->getMutableValues())[uidField - 1].mValue; 134 const int hostUid = mUidMap->getHostUidOrSelf(value.int_value); 135 updateUid(&value, hostUid); 136 } else { 137 ALOGE("Malformed log, uid not found. %s", event->ToString().c_str()); 138 } 139 } 140 } 141} 142 143void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) { 144 status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR; 145 bool is_create = event.GetBool(3, &err); 146 auto parent_uid = int(event.GetLong(1, &err2)); 147 auto isolated_uid = int(event.GetLong(2, &err3)); 148 if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) { 149 if (is_create) { 150 mUidMap->assignIsolatedUid(isolated_uid, parent_uid); 151 } else { 152 mUidMap->removeIsolatedUid(isolated_uid, parent_uid); 153 } 154 } else { 155 ALOGE("Failed to parse uid in the isolated uid change event."); 156 } 157} 158 159void StatsLogProcessor::OnLogEvent(LogEvent* event) { 160 std::lock_guard<std::mutex> lock(mMetricsMutex); 161 if (event->GetElapsedTimestampNs() < mLastLogTimestamp) { 162 return; 163 } 164 mLastLogTimestamp = event->GetElapsedTimestampNs(); 165 StatsdStats::getInstance().noteAtomLogged( 166 event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC); 167 168 // Hard-coded logic to update the isolated uid's in the uid-map. 169 // The field numbers need to be currently updated by hand with atoms.proto 170 if (event->GetTagId() == android::util::ISOLATED_UID_CHANGED) { 171 onIsolatedUidChangedEventLocked(*event); 172 } 173 174 if (mMetricsManagers.empty()) { 175 return; 176 } 177 178 uint64_t curTimeSec = getElapsedRealtimeSec(); 179 if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) { 180 mStatsPullerManager.ClearPullerCacheIfNecessary(curTimeSec); 181 mLastPullerCacheClearTimeSec = curTimeSec; 182 } 183 184 if (event->GetTagId() != android::util::ISOLATED_UID_CHANGED) { 185 // Map the isolated uid to host uid if necessary. 186 mapIsolatedUidToHostUidIfNecessaryLocked(event); 187 } 188 189 // pass the event to metrics managers. 190 for (auto& pair : mMetricsManagers) { 191 pair.second->onLogEvent(*event); 192 flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second)); 193 } 194} 195 196void StatsLogProcessor::OnConfigUpdated(const ConfigKey& key, const StatsdConfig& config) { 197 std::lock_guard<std::mutex> lock(mMetricsMutex); 198 VLOG("Updated configuration for key %s", key.ToString().c_str()); 199 sp<MetricsManager> newMetricsManager = 200 new MetricsManager(key, config, mTimeBaseSec, mUidMap, 201 mAnomalyAlarmMonitor, mPeriodicAlarmMonitor); 202 auto it = mMetricsManagers.find(key); 203 if (it == mMetricsManagers.end() && mMetricsManagers.size() > StatsdStats::kMaxConfigCount) { 204 ALOGE("Can't accept more configs!"); 205 return; 206 } 207 208 if (newMetricsManager->isConfigValid()) { 209 mUidMap->OnConfigUpdated(key); 210 if (newMetricsManager->shouldAddUidMapListener()) { 211 // We have to add listener after the MetricsManager is constructed because it's 212 // not safe to create wp or sp from this pointer inside its constructor. 213 mUidMap->addListener(newMetricsManager.get()); 214 } 215 mMetricsManagers[key] = newMetricsManager; 216 // Why doesn't this work? mMetricsManagers.insert({key, std::move(newMetricsManager)}); 217 VLOG("StatsdConfig valid"); 218 } else { 219 // If there is any error in the config, don't use it. 220 ALOGE("StatsdConfig NOT valid"); 221 } 222} 223 224size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const { 225 std::lock_guard<std::mutex> lock(mMetricsMutex); 226 auto it = mMetricsManagers.find(key); 227 if (it == mMetricsManagers.end()) { 228 ALOGW("Config source %s does not exist", key.ToString().c_str()); 229 return 0; 230 } 231 return it->second->byteSize(); 232} 233 234void StatsLogProcessor::dumpStates(FILE* out, bool verbose) { 235 std::lock_guard<std::mutex> lock(mMetricsMutex); 236 fprintf(out, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size()); 237 for (auto metricsManager : mMetricsManagers) { 238 metricsManager.second->dumpStates(out, verbose); 239 } 240} 241 242/* 243 * onDumpReport dumps serialized ConfigMetricsReportList into outData. 244 */ 245void StatsLogProcessor::onDumpReport(const ConfigKey& key, const uint64_t dumpTimeStampNs, 246 vector<uint8_t>* outData) { 247 std::lock_guard<std::mutex> lock(mMetricsMutex); 248 249 auto it = mMetricsManagers.find(key); 250 if (it == mMetricsManagers.end()) { 251 ALOGW("Config source %s does not exist", key.ToString().c_str()); 252 return; 253 } 254 255 // This allows another broadcast to be sent within the rate-limit period if we get close to 256 // filling the buffer again soon. 257 mLastBroadcastTimes.erase(key); 258 259 ProtoOutputStream proto; 260 261 // Start of ConfigKey. 262 uint64_t configKeyToken = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY); 263 proto.write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid()); 264 proto.write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId()); 265 proto.end(configKeyToken); 266 // End of ConfigKey. 267 268 // Start of ConfigMetricsReport (reports). 269 uint64_t reportsToken = 270 proto.start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS); 271 onConfigMetricsReportLocked(key, dumpTimeStampNs, &proto); 272 proto.end(reportsToken); 273 // End of ConfigMetricsReport (reports). 274 275 276 // Then, check stats-data directory to see there's any file containing 277 // ConfigMetricsReport from previous shutdowns to concatenate to reports. 278 StorageManager::appendConfigMetricsReport(key, &proto); 279 280 if (outData != nullptr) { 281 outData->clear(); 282 outData->resize(proto.size()); 283 size_t pos = 0; 284 auto iter = proto.data(); 285 while (iter.readBuffer() != NULL) { 286 size_t toRead = iter.currentToRead(); 287 std::memcpy(&((*outData)[pos]), iter.readBuffer(), toRead); 288 pos += toRead; 289 iter.rp()->move(toRead); 290 } 291 } 292 293 StatsdStats::getInstance().noteMetricsReportSent(key); 294} 295 296/* 297 * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData. 298 */ 299void StatsLogProcessor::onConfigMetricsReportLocked(const ConfigKey& key, 300 const uint64_t dumpTimeStampNs, 301 ProtoOutputStream* proto) { 302 // We already checked whether key exists in mMetricsManagers in 303 // WriteDataToDisk. 304 auto it = mMetricsManagers.find(key); 305 int64_t lastReportTimeNs = it->second->getLastReportTimeNs(); 306 int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs(); 307 308 // First, fill in ConfigMetricsReport using current data on memory, which 309 // starts from filling in StatsLogReport's. 310 it->second->onDumpReport(dumpTimeStampNs, proto); 311 312 // Fill in UidMap. 313 uint64_t uidMapToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP); 314 mUidMap->appendUidMap(key, proto); 315 proto->end(uidMapToken); 316 317 // Fill in the timestamps. 318 proto->write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS, 319 (long long)lastReportTimeNs); 320 proto->write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS, 321 (long long)dumpTimeStampNs); 322 proto->write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS, 323 (long long)lastReportWallClockNs); 324 proto->write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS, 325 (long long)getWallClockNs()); 326 327 328} 329 330void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) { 331 std::lock_guard<std::mutex> lock(mMetricsMutex); 332 auto it = mMetricsManagers.find(key); 333 if (it != mMetricsManagers.end()) { 334 mMetricsManagers.erase(it); 335 mUidMap->OnConfigRemoved(key); 336 } 337 StatsdStats::getInstance().noteConfigRemoved(key); 338 339 mLastBroadcastTimes.erase(key); 340 341 if (mMetricsManagers.empty()) { 342 mStatsPullerManager.ForceClearPullerCache(); 343 } 344} 345 346void StatsLogProcessor::flushIfNecessaryLocked( 347 uint64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) { 348 auto lastCheckTime = mLastByteSizeTimes.find(key); 349 if (lastCheckTime != mLastByteSizeTimes.end()) { 350 if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) { 351 return; 352 } 353 } 354 355 // We suspect that the byteSize() computation is expensive, so we set a rate limit. 356 size_t totalBytes = metricsManager.byteSize(); 357 mLastByteSizeTimes[key] = timestampNs; 358 if (totalBytes > 359 StatsdStats::kMaxMetricsBytesPerConfig) { // Too late. We need to start clearing data. 360 metricsManager.dropData(timestampNs); 361 StatsdStats::getInstance().noteDataDropped(key); 362 VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str()); 363 } else if (totalBytes > .9 * StatsdStats::kMaxMetricsBytesPerConfig) { 364 // Send broadcast so that receivers can pull data. 365 auto lastBroadcastTime = mLastBroadcastTimes.find(key); 366 if (lastBroadcastTime != mLastBroadcastTimes.end()) { 367 if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) { 368 VLOG("StatsD would've sent a broadcast but the rate limit stopped us."); 369 return; 370 } 371 } 372 mLastBroadcastTimes[key] = timestampNs; 373 VLOG("StatsD requesting broadcast for %s", key.ToString().c_str()); 374 mSendBroadcast(key); 375 StatsdStats::getInstance().noteBroadcastSent(key); 376 } 377} 378 379void StatsLogProcessor::WriteDataToDisk() { 380 std::lock_guard<std::mutex> lock(mMetricsMutex); 381 for (auto& pair : mMetricsManagers) { 382 const ConfigKey& key = pair.first; 383 ProtoOutputStream proto; 384 onConfigMetricsReportLocked(key, getElapsedRealtimeNs(), &proto); 385 string file_name = StringPrintf("%s/%ld_%d_%lld", STATS_DATA_DIR, 386 (long)getWallClockSec(), key.GetUid(), (long long)key.GetId()); 387 android::base::unique_fd fd(open(file_name.c_str(), 388 O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR)); 389 if (fd == -1) { 390 VLOG("Attempt to write %s but failed", file_name.c_str()); 391 return; 392 } 393 proto.flush(fd.get()); 394 } 395} 396 397} // namespace statsd 398} // namespace os 399} // namespace android 400