/* * Copyright (C) 2017 The Android Open Source Project * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. */ #define DEBUG true // STOPSHIP if true #include "Log.h" #include "statslog.h" #include #include #include "StatsLogProcessor.h" #include "stats_log_util.h" #include "android-base/stringprintf.h" #include "guardrail/StatsdStats.h" #include "metrics/CountMetricProducer.h" #include "external/StatsPullerManager.h" #include "stats_util.h" #include "storage/StorageManager.h" #include #include #include using namespace android; using android::base::StringPrintf; using android::util::FIELD_COUNT_REPEATED; using android::util::FIELD_TYPE_BOOL; using android::util::FIELD_TYPE_FLOAT; using android::util::FIELD_TYPE_INT32; using android::util::FIELD_TYPE_INT64; using android::util::FIELD_TYPE_MESSAGE; using android::util::FIELD_TYPE_STRING; using android::util::ProtoOutputStream; using std::make_unique; using std::unique_ptr; using std::vector; namespace android { namespace os { namespace statsd { // for ConfigMetricsReportList const int FIELD_ID_CONFIG_KEY = 1; const int FIELD_ID_REPORTS = 2; // for ConfigKey const int FIELD_ID_UID = 1; const int FIELD_ID_ID = 2; // for ConfigMetricsReport // const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp const int FIELD_ID_UID_MAP = 2; const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3; const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4; const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5; const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6; #define STATS_DATA_DIR "/data/misc/stats-data" StatsLogProcessor::StatsLogProcessor(const sp& uidMap, const sp& anomalyAlarmMonitor, const sp& periodicAlarmMonitor, const long timeBaseSec, const std::function& sendBroadcast) : mUidMap(uidMap), mAnomalyAlarmMonitor(anomalyAlarmMonitor), mPeriodicAlarmMonitor(periodicAlarmMonitor), mSendBroadcast(sendBroadcast), mTimeBaseSec(timeBaseSec), mLastLogTimestamp(0) { StatsPullerManager statsPullerManager; statsPullerManager.SetTimeBaseSec(mTimeBaseSec); } StatsLogProcessor::~StatsLogProcessor() { } void StatsLogProcessor::onAnomalyAlarmFired( const uint64_t timestampNs, unordered_set, SpHash> alarmSet) { std::lock_guard lock(mMetricsMutex); for (const auto& itr : mMetricsManagers) { itr.second->onAnomalyAlarmFired(timestampNs, alarmSet); } } void StatsLogProcessor::onPeriodicAlarmFired( const uint64_t timestampNs, unordered_set, SpHash> alarmSet) { std::lock_guard lock(mMetricsMutex); for (const auto& itr : mMetricsManagers) { itr.second->onPeriodicAlarmFired(timestampNs, alarmSet); } } void updateUid(Value* value, int hostUid) { int uid = value->int_value; if (uid != hostUid) { value->setInt(hostUid); } } void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const { if (android::util::kAtomsWithAttributionChain.find(event->GetTagId()) != android::util::kAtomsWithAttributionChain.end()) { for (auto& value : *(event->getMutableValues())) { if (value.mField.getPosAtDepth(0) > kAttributionField) { break; } if (isAttributionUidField(value)) { const int hostUid = mUidMap->getHostUidOrSelf(value.mValue.int_value); updateUid(&value.mValue, hostUid); } } } else if (android::util::kAtomsWithUidField.find(event->GetTagId()) != android::util::kAtomsWithUidField.end() && event->getValues().size() > 0 && (event->getValues())[0].mValue.getType() == INT) { Value& value = (*event->getMutableValues())[0].mValue; const int hostUid = mUidMap->getHostUidOrSelf(value.int_value); updateUid(&value, hostUid); } } void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) { status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR; bool is_create = event.GetBool(3, &err); auto parent_uid = int(event.GetLong(1, &err2)); auto isolated_uid = int(event.GetLong(2, &err3)); if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) { if (is_create) { mUidMap->assignIsolatedUid(isolated_uid, parent_uid); } else { mUidMap->removeIsolatedUid(isolated_uid, parent_uid); } } else { ALOGE("Failed to parse uid in the isolated uid change event."); } } void StatsLogProcessor::OnLogEvent(LogEvent* event) { std::lock_guard lock(mMetricsMutex); if (event->GetElapsedTimestampNs() < mLastLogTimestamp) { return; } mLastLogTimestamp = event->GetElapsedTimestampNs(); StatsdStats::getInstance().noteAtomLogged( event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC); // Hard-coded logic to update the isolated uid's in the uid-map. // The field numbers need to be currently updated by hand with atoms.proto if (event->GetTagId() == android::util::ISOLATED_UID_CHANGED) { onIsolatedUidChangedEventLocked(*event); } if (mMetricsManagers.empty()) { return; } uint64_t curTimeSec = getElapsedRealtimeSec(); if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) { mStatsPullerManager.ClearPullerCacheIfNecessary(curTimeSec); mLastPullerCacheClearTimeSec = curTimeSec; } if (event->GetTagId() != android::util::ISOLATED_UID_CHANGED) { // Map the isolated uid to host uid if necessary. mapIsolatedUidToHostUidIfNecessaryLocked(event); } // pass the event to metrics managers. for (auto& pair : mMetricsManagers) { pair.second->onLogEvent(*event); flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second)); } } void StatsLogProcessor::OnConfigUpdated(const ConfigKey& key, const StatsdConfig& config) { std::lock_guard lock(mMetricsMutex); VLOG("Updated configuration for key %s", key.ToString().c_str()); sp newMetricsManager = new MetricsManager(key, config, mTimeBaseSec, mUidMap, mAnomalyAlarmMonitor, mPeriodicAlarmMonitor); auto it = mMetricsManagers.find(key); if (it == mMetricsManagers.end() && mMetricsManagers.size() > StatsdStats::kMaxConfigCount) { ALOGE("Can't accept more configs!"); return; } if (newMetricsManager->isConfigValid()) { mUidMap->OnConfigUpdated(key); if (newMetricsManager->shouldAddUidMapListener()) { // We have to add listener after the MetricsManager is constructed because it's // not safe to create wp or sp from this pointer inside its constructor. mUidMap->addListener(newMetricsManager.get()); } mMetricsManagers[key] = newMetricsManager; // Why doesn't this work? mMetricsManagers.insert({key, std::move(newMetricsManager)}); VLOG("StatsdConfig valid"); } else { // If there is any error in the config, don't use it. ALOGE("StatsdConfig NOT valid"); } } size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const { std::lock_guard lock(mMetricsMutex); auto it = mMetricsManagers.find(key); if (it == mMetricsManagers.end()) { ALOGW("Config source %s does not exist", key.ToString().c_str()); return 0; } return it->second->byteSize(); } void StatsLogProcessor::dumpStates(FILE* out, bool verbose) { std::lock_guard lock(mMetricsMutex); fprintf(out, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size()); for (auto metricsManager : mMetricsManagers) { metricsManager.second->dumpStates(out, verbose); } } /* * onDumpReport dumps serialized ConfigMetricsReportList into outData. */ void StatsLogProcessor::onDumpReport(const ConfigKey& key, const uint64_t dumpTimeStampNs, vector* outData) { std::lock_guard lock(mMetricsMutex); auto it = mMetricsManagers.find(key); if (it == mMetricsManagers.end()) { ALOGW("Config source %s does not exist", key.ToString().c_str()); return; } // This allows another broadcast to be sent within the rate-limit period if we get close to // filling the buffer again soon. mLastBroadcastTimes.erase(key); ProtoOutputStream proto; // Start of ConfigKey. uint64_t configKeyToken = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY); proto.write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid()); proto.write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId()); proto.end(configKeyToken); // End of ConfigKey. // Start of ConfigMetricsReport (reports). uint64_t reportsToken = proto.start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS); onConfigMetricsReportLocked(key, dumpTimeStampNs, &proto); proto.end(reportsToken); // End of ConfigMetricsReport (reports). // Then, check stats-data directory to see there's any file containing // ConfigMetricsReport from previous shutdowns to concatenate to reports. StorageManager::appendConfigMetricsReport(key, &proto); if (outData != nullptr) { outData->clear(); outData->resize(proto.size()); size_t pos = 0; auto iter = proto.data(); while (iter.readBuffer() != NULL) { size_t toRead = iter.currentToRead(); std::memcpy(&((*outData)[pos]), iter.readBuffer(), toRead); pos += toRead; iter.rp()->move(toRead); } } StatsdStats::getInstance().noteMetricsReportSent(key); } /* * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData. */ void StatsLogProcessor::onConfigMetricsReportLocked(const ConfigKey& key, const uint64_t dumpTimeStampNs, ProtoOutputStream* proto) { // We already checked whether key exists in mMetricsManagers in // WriteDataToDisk. auto it = mMetricsManagers.find(key); int64_t lastReportTimeNs = it->second->getLastReportTimeNs(); int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs(); // First, fill in ConfigMetricsReport using current data on memory, which // starts from filling in StatsLogReport's. it->second->onDumpReport(dumpTimeStampNs, proto); // Fill in UidMap. uint64_t uidMapToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP); mUidMap->appendUidMap(key, proto); proto->end(uidMapToken); // Fill in the timestamps. proto->write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS, (long long)lastReportTimeNs); proto->write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS, (long long)dumpTimeStampNs); proto->write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS, (long long)lastReportWallClockNs); proto->write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS, (long long)getWallClockNs()); } void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) { std::lock_guard lock(mMetricsMutex); auto it = mMetricsManagers.find(key); if (it != mMetricsManagers.end()) { mMetricsManagers.erase(it); mUidMap->OnConfigRemoved(key); } StatsdStats::getInstance().noteConfigRemoved(key); mLastBroadcastTimes.erase(key); if (mMetricsManagers.empty()) { mStatsPullerManager.ForceClearPullerCache(); } } void StatsLogProcessor::flushIfNecessaryLocked( uint64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) { auto lastCheckTime = mLastByteSizeTimes.find(key); if (lastCheckTime != mLastByteSizeTimes.end()) { if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) { return; } } // We suspect that the byteSize() computation is expensive, so we set a rate limit. size_t totalBytes = metricsManager.byteSize(); mLastByteSizeTimes[key] = timestampNs; if (totalBytes > StatsdStats::kMaxMetricsBytesPerConfig) { // Too late. We need to start clearing data. metricsManager.dropData(timestampNs); StatsdStats::getInstance().noteDataDropped(key); VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str()); } else if (totalBytes > .9 * StatsdStats::kMaxMetricsBytesPerConfig) { // Send broadcast so that receivers can pull data. auto lastBroadcastTime = mLastBroadcastTimes.find(key); if (lastBroadcastTime != mLastBroadcastTimes.end()) { if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) { VLOG("StatsD would've sent a broadcast but the rate limit stopped us."); return; } } mLastBroadcastTimes[key] = timestampNs; VLOG("StatsD requesting broadcast for %s", key.ToString().c_str()); mSendBroadcast(key); StatsdStats::getInstance().noteBroadcastSent(key); } } void StatsLogProcessor::WriteDataToDisk() { std::lock_guard lock(mMetricsMutex); for (auto& pair : mMetricsManagers) { const ConfigKey& key = pair.first; ProtoOutputStream proto; onConfigMetricsReportLocked(key, getElapsedRealtimeNs(), &proto); string file_name = StringPrintf("%s/%ld_%d_%lld", STATS_DATA_DIR, (long)getWallClockSec(), key.GetUid(), (long long)key.GetId()); android::base::unique_fd fd(open(file_name.c_str(), O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR)); if (fd == -1) { VLOG("Attempt to write %s but failed", file_name.c_str()); return; } proto.flush(fd.get()); } } } // namespace statsd } // namespace os } // namespace android