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