• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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 
20 #include "StatsLogProcessor.h"
21 
22 #include <android-base/file.h>
23 #include <cutils/multiuser.h>
24 #include <src/active_config_list.pb.h>
25 #include <src/experiment_ids.pb.h>
26 
27 #include "StatsService.h"
28 #include "android-base/stringprintf.h"
29 #include "external/StatsPullerManager.h"
30 #include "flags/flags.h"
31 #include "guardrail/StatsdStats.h"
32 #include "logd/LogEvent.h"
33 #include "metrics/CountMetricProducer.h"
34 #include "state/StateManager.h"
35 #include "stats_log_util.h"
36 #include "stats_util.h"
37 #include "statslog_statsd.h"
38 #include "storage/StorageManager.h"
39 
40 using namespace android;
41 using android::base::StringPrintf;
42 using android::util::FIELD_COUNT_REPEATED;
43 using android::util::FIELD_TYPE_BOOL;
44 using android::util::FIELD_TYPE_FLOAT;
45 using android::util::FIELD_TYPE_INT32;
46 using android::util::FIELD_TYPE_INT64;
47 using android::util::FIELD_TYPE_MESSAGE;
48 using android::util::FIELD_TYPE_STRING;
49 using android::util::ProtoOutputStream;
50 using std::vector;
51 
52 namespace android {
53 namespace os {
54 namespace statsd {
55 
56 // for ConfigMetricsReportList
57 const int FIELD_ID_CONFIG_KEY = 1;
58 const int FIELD_ID_REPORTS = 2;
59 // for ConfigKey
60 const int FIELD_ID_UID = 1;
61 const int FIELD_ID_ID = 2;
62 // for ConfigMetricsReport
63 // const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp
64 const int FIELD_ID_UID_MAP = 2;
65 const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3;
66 const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4;
67 const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5;
68 const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6;
69 const int FIELD_ID_DUMP_REPORT_REASON = 8;
70 const int FIELD_ID_STRINGS = 9;
71 
72 // for ActiveConfigList
73 const int FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG = 1;
74 
75 // for permissions checks
76 constexpr const char* kPermissionDump = "android.permission.DUMP";
77 constexpr const char* kPermissionUsage = "android.permission.PACKAGE_USAGE_STATS";
78 
79 #define NS_PER_HOUR 3600 * NS_PER_SEC
80 
81 #define STATS_ACTIVE_METRIC_DIR "/data/misc/stats-active-metric"
82 #define STATS_METADATA_DIR "/data/misc/stats-metadata"
83 
84 // Cool down period for writing data to disk to avoid overwriting files.
85 #define WRITE_DATA_COOL_DOWN_SEC 15
86 
StatsLogProcessor(const sp<UidMap> & uidMap,const sp<StatsPullerManager> & pullerManager,const sp<AlarmMonitor> & anomalyAlarmMonitor,const sp<AlarmMonitor> & periodicAlarmMonitor,const int64_t timeBaseNs,const std::function<bool (const ConfigKey &)> & sendBroadcast,const std::function<bool (const int &,const vector<int64_t> &)> & activateBroadcast)87 StatsLogProcessor::StatsLogProcessor(const sp<UidMap>& uidMap,
88                                      const sp<StatsPullerManager>& pullerManager,
89                                      const sp<AlarmMonitor>& anomalyAlarmMonitor,
90                                      const sp<AlarmMonitor>& periodicAlarmMonitor,
91                                      const int64_t timeBaseNs,
92                                      const std::function<bool(const ConfigKey&)>& sendBroadcast,
93                                      const std::function<bool(
94                                             const int&, const vector<int64_t>&)>& activateBroadcast)
95     : mUidMap(uidMap),
96       mPullerManager(pullerManager),
97       mAnomalyAlarmMonitor(anomalyAlarmMonitor),
98       mPeriodicAlarmMonitor(periodicAlarmMonitor),
99       mSendBroadcast(sendBroadcast),
100       mSendActivationBroadcast(activateBroadcast),
101       mTimeBaseNs(timeBaseNs),
102       mLargestTimestampSeen(0),
103       mLastTimestampSeen(0) {
104     mPullerManager->ForceClearPullerCache();
105     StateManager::getInstance().updateLogSources(uidMap);
106 }
107 
~StatsLogProcessor()108 StatsLogProcessor::~StatsLogProcessor() {
109 }
110 
flushProtoToBuffer(ProtoOutputStream & proto,vector<uint8_t> * outData)111 static void flushProtoToBuffer(ProtoOutputStream& proto, vector<uint8_t>* outData) {
112     outData->clear();
113     outData->resize(proto.size());
114     size_t pos = 0;
115     sp<android::util::ProtoReader> reader = proto.data();
116     while (reader->readBuffer() != NULL) {
117         size_t toRead = reader->currentToRead();
118         std::memcpy(&((*outData)[pos]), reader->readBuffer(), toRead);
119         pos += toRead;
120         reader->move(toRead);
121     }
122 }
123 
processFiredAnomalyAlarmsLocked(const int64_t & timestampNs,unordered_set<sp<const InternalAlarm>,SpHash<InternalAlarm>> alarmSet)124 void StatsLogProcessor::processFiredAnomalyAlarmsLocked(
125         const int64_t& timestampNs,
126         unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
127     for (const auto& itr : mMetricsManagers) {
128         itr.second->onAnomalyAlarmFired(timestampNs, alarmSet);
129     }
130 }
onPeriodicAlarmFired(const int64_t & timestampNs,unordered_set<sp<const InternalAlarm>,SpHash<InternalAlarm>> alarmSet)131 void StatsLogProcessor::onPeriodicAlarmFired(
132         const int64_t& timestampNs,
133         unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
134 
135     std::lock_guard<std::mutex> lock(mMetricsMutex);
136     for (const auto& itr : mMetricsManagers) {
137         itr.second->onPeriodicAlarmFired(timestampNs, alarmSet);
138     }
139 }
140 
mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent * event) const141 void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const {
142     if (std::pair<int, int> indexRange; event->hasAttributionChain(&indexRange)) {
143         vector<FieldValue>* const fieldValues = event->getMutableValues();
144         for (int i = indexRange.first; i <= indexRange.second; i++) {
145             FieldValue& fieldValue = fieldValues->at(i);
146             if (isAttributionUidField(fieldValue)) {
147                 const int hostUid = mUidMap->getHostUidOrSelf(fieldValue.mValue.int_value);
148                 fieldValue.mValue.setInt(hostUid);
149             }
150         }
151     } else {
152         int uidFieldIndex = event->getUidFieldIndex();
153         if (uidFieldIndex != -1) {
154            Value& value = (*event->getMutableValues())[uidFieldIndex].mValue;
155            const int hostUid = mUidMap->getHostUidOrSelf(value.int_value);
156            value.setInt(hostUid);
157         }
158     }
159 }
160 
onIsolatedUidChangedEventLocked(const LogEvent & event)161 void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
162     status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR;
163     bool is_create = event.GetBool(3, &err);
164     auto parent_uid = int(event.GetLong(1, &err2));
165     auto isolated_uid = int(event.GetLong(2, &err3));
166     if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) {
167         if (is_create) {
168             mUidMap->assignIsolatedUid(isolated_uid, parent_uid);
169         } else {
170             mUidMap->removeIsolatedUid(isolated_uid);
171         }
172     } else {
173         ALOGE("Failed to parse uid in the isolated uid change event.");
174     }
175 }
176 
onBinaryPushStateChangedEventLocked(LogEvent * event)177 void StatsLogProcessor::onBinaryPushStateChangedEventLocked(LogEvent* event) {
178     pid_t pid = event->GetPid();
179     uid_t uid = event->GetUid();
180     if (!checkPermissionForIds(kPermissionDump, pid, uid) ||
181         !checkPermissionForIds(kPermissionUsage, pid, uid)) {
182         return;
183     }
184     // The Get* functions don't modify the status on success, they only write in
185     // failure statuses, so we can use one status variable for all calls then
186     // check if it is no longer NO_ERROR.
187     status_t err = NO_ERROR;
188     InstallTrainInfo trainInfo;
189     trainInfo.trainName = string(event->GetString(1 /*train name field id*/, &err));
190     trainInfo.trainVersionCode = event->GetLong(2 /*train version field id*/, &err);
191     trainInfo.requiresStaging = event->GetBool(3 /*requires staging field id*/, &err);
192     trainInfo.rollbackEnabled = event->GetBool(4 /*rollback enabled field id*/, &err);
193     trainInfo.requiresLowLatencyMonitor =
194             event->GetBool(5 /*requires low latency monitor field id*/, &err);
195     trainInfo.status = int32_t(event->GetLong(6 /*state field id*/, &err));
196     std::vector<uint8_t> trainExperimentIdBytes =
197             event->GetStorage(7 /*experiment ids field id*/, &err);
198     bool is_rollback = event->GetBool(10 /*is rollback field id*/, &err);
199 
200     if (err != NO_ERROR) {
201         ALOGE("Failed to parse fields in binary push state changed log event");
202         return;
203     }
204     ExperimentIds trainExperimentIds;
205     if (!trainExperimentIds.ParseFromArray(trainExperimentIdBytes.data(),
206                                            trainExperimentIdBytes.size())) {
207         ALOGE("Failed to parse experimentids in binary push state changed.");
208         return;
209     }
210     trainInfo.experimentIds = {trainExperimentIds.experiment_id().begin(),
211                                trainExperimentIds.experiment_id().end()};
212 
213     // Update the train info on disk and get any data the logevent is missing.
214     getAndUpdateTrainInfoOnDisk(is_rollback, &trainInfo);
215 
216     std::vector<uint8_t> trainExperimentIdProto;
217     writeExperimentIdsToProto(trainInfo.experimentIds, &trainExperimentIdProto);
218     int32_t userId = multiuser_get_user_id(uid);
219 
220     event->updateValue(2 /*train version field id*/, trainInfo.trainVersionCode, LONG);
221     event->updateValue(7 /*experiment ids field id*/, trainExperimentIdProto, STORAGE);
222     event->updateValue(8 /*user id field id*/, userId, INT);
223 
224     // If this event is a rollback event, then the following bits in the event
225     // are invalid and we will need to update them with the values we pulled
226     // from disk.
227     if (is_rollback) {
228         int bit = trainInfo.requiresStaging ? 1 : 0;
229         event->updateValue(3 /*requires staging field id*/, bit, INT);
230         bit = trainInfo.rollbackEnabled ? 1 : 0;
231         event->updateValue(4 /*rollback enabled field id*/, bit, INT);
232         bit = trainInfo.requiresLowLatencyMonitor ? 1 : 0;
233         event->updateValue(5 /*requires low latency monitor field id*/, bit, INT);
234     }
235 }
236 
getAndUpdateTrainInfoOnDisk(bool is_rollback,InstallTrainInfo * trainInfo)237 void StatsLogProcessor::getAndUpdateTrainInfoOnDisk(bool is_rollback,
238                                                     InstallTrainInfo* trainInfo) {
239     // If the train name is empty, we don't know which train to attribute the
240     // event to, so return early.
241     if (trainInfo->trainName.empty()) {
242         return;
243     }
244     bool readTrainInfoSuccess = false;
245     InstallTrainInfo trainInfoOnDisk;
246     readTrainInfoSuccess = StorageManager::readTrainInfo(trainInfo->trainName, trainInfoOnDisk);
247 
248     bool resetExperimentIds = false;
249     if (readTrainInfoSuccess) {
250         // Keep the old train version if we received an empty version.
251         if (trainInfo->trainVersionCode == -1) {
252             trainInfo->trainVersionCode = trainInfoOnDisk.trainVersionCode;
253         } else if (trainInfo->trainVersionCode != trainInfoOnDisk.trainVersionCode) {
254             // Reset experiment ids if we receive a new non-empty train version.
255             resetExperimentIds = true;
256         }
257 
258         // Reset if we received a different experiment id.
259         if (!trainInfo->experimentIds.empty() &&
260             (trainInfoOnDisk.experimentIds.empty() ||
261              trainInfo->experimentIds.at(0) != trainInfoOnDisk.experimentIds[0])) {
262             resetExperimentIds = true;
263         }
264     }
265 
266     // Find the right experiment IDs
267     if ((!resetExperimentIds || is_rollback) && readTrainInfoSuccess) {
268         trainInfo->experimentIds = trainInfoOnDisk.experimentIds;
269     }
270 
271     if (!trainInfo->experimentIds.empty()) {
272         int64_t firstId = trainInfo->experimentIds.at(0);
273         auto& ids = trainInfo->experimentIds;
274         switch (trainInfo->status) {
275             case android::os::statsd::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALL_SUCCESS:
276                 if (find(ids.begin(), ids.end(), firstId + 1) == ids.end()) {
277                     ids.push_back(firstId + 1);
278                 }
279                 break;
280             case android::os::statsd::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_INITIATED:
281                 if (find(ids.begin(), ids.end(), firstId + 2) == ids.end()) {
282                     ids.push_back(firstId + 2);
283                 }
284                 break;
285             case android::os::statsd::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_SUCCESS:
286                 if (find(ids.begin(), ids.end(), firstId + 3) == ids.end()) {
287                     ids.push_back(firstId + 3);
288                 }
289                 break;
290         }
291     }
292 
293     // If this event is a rollback event, the following fields are invalid and
294     // need to be replaced by the fields stored to disk.
295     if (is_rollback) {
296         trainInfo->requiresStaging = trainInfoOnDisk.requiresStaging;
297         trainInfo->rollbackEnabled = trainInfoOnDisk.rollbackEnabled;
298         trainInfo->requiresLowLatencyMonitor = trainInfoOnDisk.requiresLowLatencyMonitor;
299     }
300 
301     StorageManager::writeTrainInfo(*trainInfo);
302 }
303 
onWatchdogRollbackOccurredLocked(LogEvent * event)304 void StatsLogProcessor::onWatchdogRollbackOccurredLocked(LogEvent* event) {
305     pid_t pid = event->GetPid();
306     uid_t uid = event->GetUid();
307     if (!checkPermissionForIds(kPermissionDump, pid, uid) ||
308         !checkPermissionForIds(kPermissionUsage, pid, uid)) {
309         return;
310     }
311     // The Get* functions don't modify the status on success, they only write in
312     // failure statuses, so we can use one status variable for all calls then
313     // check if it is no longer NO_ERROR.
314     status_t err = NO_ERROR;
315     int32_t rollbackType = int32_t(event->GetInt(1 /*rollback type field id*/, &err));
316     string packageName = string(event->GetString(2 /*package name field id*/, &err));
317 
318     if (err != NO_ERROR) {
319         ALOGE("Failed to parse fields in watchdog rollback occurred log event");
320         return;
321     }
322 
323     vector<int64_t> experimentIds =
324         processWatchdogRollbackOccurred(rollbackType, packageName);
325     vector<uint8_t> experimentIdProto;
326     writeExperimentIdsToProto(experimentIds, &experimentIdProto);
327 
328     event->updateValue(6 /*experiment ids field id*/, experimentIdProto, STORAGE);
329 }
330 
processWatchdogRollbackOccurred(const int32_t rollbackTypeIn,const string & packageNameIn)331 vector<int64_t> StatsLogProcessor::processWatchdogRollbackOccurred(const int32_t rollbackTypeIn,
332                                                                     const string& packageNameIn) {
333     // If the package name is empty, we can't attribute it to any train, so
334     // return early.
335     if (packageNameIn.empty()) {
336       return vector<int64_t>();
337     }
338     bool readTrainInfoSuccess = false;
339     InstallTrainInfo trainInfoOnDisk;
340     // We use the package name of the event as the train name.
341     readTrainInfoSuccess = StorageManager::readTrainInfo(packageNameIn, trainInfoOnDisk);
342 
343     if (!readTrainInfoSuccess) {
344         return vector<int64_t>();
345     }
346 
347     if (trainInfoOnDisk.experimentIds.empty()) {
348         return vector<int64_t>();
349     }
350 
351     int64_t firstId = trainInfoOnDisk.experimentIds[0];
352     auto& ids = trainInfoOnDisk.experimentIds;
353     switch (rollbackTypeIn) {
354       case android::os::statsd::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_INITIATE:
355             if (find(ids.begin(), ids.end(), firstId + 4) == ids.end()) {
356                 ids.push_back(firstId + 4);
357             }
358             StorageManager::writeTrainInfo(trainInfoOnDisk);
359             break;
360       case android::os::statsd::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS:
361             if (find(ids.begin(), ids.end(), firstId + 5) == ids.end()) {
362                 ids.push_back(firstId + 5);
363             }
364             StorageManager::writeTrainInfo(trainInfoOnDisk);
365             break;
366     }
367 
368     return trainInfoOnDisk.experimentIds;
369 }
370 
resetConfigs()371 void StatsLogProcessor::resetConfigs() {
372     std::lock_guard<std::mutex> lock(mMetricsMutex);
373     resetConfigsLocked(getElapsedRealtimeNs());
374 }
375 
resetConfigsLocked(const int64_t timestampNs)376 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) {
377     std::vector<ConfigKey> configKeys;
378     for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
379         configKeys.push_back(it->first);
380     }
381     resetConfigsLocked(timestampNs, configKeys);
382 }
383 
OnLogEvent(LogEvent * event)384 void StatsLogProcessor::OnLogEvent(LogEvent* event) {
385     OnLogEvent(event, getElapsedRealtimeNs());
386 }
387 
OnLogEvent(LogEvent * event,int64_t elapsedRealtimeNs)388 void StatsLogProcessor::OnLogEvent(LogEvent* event, int64_t elapsedRealtimeNs) {
389     std::lock_guard<std::mutex> lock(mMetricsMutex);
390 
391     // Tell StatsdStats about new event
392     const int64_t eventElapsedTimeNs = event->GetElapsedTimestampNs();
393     int atomId = event->GetTagId();
394     StatsdStats::getInstance().noteAtomLogged(atomId, eventElapsedTimeNs / NS_PER_SEC);
395     if (!event->isValid()) {
396         StatsdStats::getInstance().noteAtomError(atomId);
397         return;
398     }
399 
400     // Hard-coded logic to update train info on disk and fill in any information
401     // this log event may be missing.
402     if (atomId == android::os::statsd::util::BINARY_PUSH_STATE_CHANGED) {
403         onBinaryPushStateChangedEventLocked(event);
404     }
405 
406     // Hard-coded logic to update experiment ids on disk for certain rollback
407     // types and fill the rollback atom with experiment ids
408     if (atomId == android::os::statsd::util::WATCHDOG_ROLLBACK_OCCURRED) {
409         onWatchdogRollbackOccurredLocked(event);
410     }
411 
412     if (mPrintAllLogs) {
413         ALOGI("%s", event->ToString().c_str());
414     }
415     resetIfConfigTtlExpiredLocked(eventElapsedTimeNs);
416 
417     // Hard-coded logic to update the isolated uid's in the uid-map.
418     // The field numbers need to be currently updated by hand with atoms.proto
419     if (atomId == android::os::statsd::util::ISOLATED_UID_CHANGED) {
420         onIsolatedUidChangedEventLocked(*event);
421     } else {
422         // Map the isolated uid to host uid if necessary.
423         mapIsolatedUidToHostUidIfNecessaryLocked(event);
424     }
425 
426     StateManager::getInstance().onLogEvent(*event);
427 
428     if (mMetricsManagers.empty()) {
429         return;
430     }
431 
432     bool fireAlarm = false;
433     {
434         std::lock_guard<std::mutex> anomalyLock(mAnomalyAlarmMutex);
435         if (mNextAnomalyAlarmTime != 0 &&
436             MillisToNano(mNextAnomalyAlarmTime) <= elapsedRealtimeNs) {
437             mNextAnomalyAlarmTime = 0;
438             VLOG("informing anomaly alarm at time %lld", (long long)elapsedRealtimeNs);
439             fireAlarm = true;
440         }
441     }
442     if (fireAlarm) {
443         informAnomalyAlarmFiredLocked(NanoToMillis(elapsedRealtimeNs));
444     }
445 
446     int64_t curTimeSec = getElapsedRealtimeSec();
447     if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
448         mPullerManager->ClearPullerCacheIfNecessary(curTimeSec * NS_PER_SEC);
449         mLastPullerCacheClearTimeSec = curTimeSec;
450     }
451 
452     std::unordered_set<int> uidsWithActiveConfigsChanged;
453     std::unordered_map<int, std::vector<int64_t>> activeConfigsPerUid;
454     // pass the event to metrics managers.
455     for (auto& pair : mMetricsManagers) {
456         int uid = pair.first.GetUid();
457         int64_t configId = pair.first.GetId();
458         bool isPrevActive = pair.second->isActive();
459         pair.second->onLogEvent(*event);
460         bool isCurActive = pair.second->isActive();
461         // Map all active configs by uid.
462         if (isCurActive) {
463             auto activeConfigs = activeConfigsPerUid.find(uid);
464             if (activeConfigs != activeConfigsPerUid.end()) {
465                 activeConfigs->second.push_back(configId);
466             } else {
467                 vector<int64_t> newActiveConfigs;
468                 newActiveConfigs.push_back(configId);
469                 activeConfigsPerUid[uid] = newActiveConfigs;
470             }
471         }
472         // The activation state of this config changed.
473         if (isPrevActive != isCurActive) {
474             VLOG("Active status changed for uid  %d", uid);
475             uidsWithActiveConfigsChanged.insert(uid);
476             StatsdStats::getInstance().noteActiveStatusChanged(pair.first, isCurActive);
477         }
478         flushIfNecessaryLocked(pair.first, *(pair.second));
479     }
480 
481     // Don't use the event timestamp for the guardrail.
482     for (int uid : uidsWithActiveConfigsChanged) {
483         // Send broadcast so that receivers can pull data.
484         auto lastBroadcastTime = mLastActivationBroadcastTimes.find(uid);
485         if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) {
486             if (elapsedRealtimeNs - lastBroadcastTime->second <
487                 StatsdStats::kMinActivationBroadcastPeriodNs) {
488                 StatsdStats::getInstance().noteActivationBroadcastGuardrailHit(uid);
489                 VLOG("StatsD would've sent an activation broadcast but the rate limit stopped us.");
490                 return;
491             }
492         }
493         auto activeConfigs = activeConfigsPerUid.find(uid);
494         if (activeConfigs != activeConfigsPerUid.end()) {
495             if (mSendActivationBroadcast(uid, activeConfigs->second)) {
496                 VLOG("StatsD sent activation notice for uid %d", uid);
497                 mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
498             }
499         } else {
500             std::vector<int64_t> emptyActiveConfigs;
501             if (mSendActivationBroadcast(uid, emptyActiveConfigs)) {
502                 VLOG("StatsD sent EMPTY activation notice for uid %d", uid);
503                 mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
504             }
505         }
506     }
507 }
508 
GetActiveConfigs(const int uid,vector<int64_t> & outActiveConfigs)509 void StatsLogProcessor::GetActiveConfigs(const int uid, vector<int64_t>& outActiveConfigs) {
510     std::lock_guard<std::mutex> lock(mMetricsMutex);
511     GetActiveConfigsLocked(uid, outActiveConfigs);
512 }
513 
GetActiveConfigsLocked(const int uid,vector<int64_t> & outActiveConfigs)514 void StatsLogProcessor::GetActiveConfigsLocked(const int uid, vector<int64_t>& outActiveConfigs) {
515     outActiveConfigs.clear();
516     for (auto& pair : mMetricsManagers) {
517         if (pair.first.GetUid() == uid && pair.second->isActive()) {
518             outActiveConfigs.push_back(pair.first.GetId());
519         }
520     }
521 }
522 
OnConfigUpdated(const int64_t timestampNs,const ConfigKey & key,const StatsdConfig & config,bool modularUpdate)523 void StatsLogProcessor::OnConfigUpdated(const int64_t timestampNs, const ConfigKey& key,
524                                         const StatsdConfig& config, bool modularUpdate) {
525     std::lock_guard<std::mutex> lock(mMetricsMutex);
526     WriteDataToDiskLocked(key, timestampNs, CONFIG_UPDATED, NO_TIME_CONSTRAINTS);
527     OnConfigUpdatedLocked(timestampNs, key, config, modularUpdate);
528 }
529 
OnConfigUpdatedLocked(const int64_t timestampNs,const ConfigKey & key,const StatsdConfig & config,bool modularUpdate)530 void StatsLogProcessor::OnConfigUpdatedLocked(const int64_t timestampNs, const ConfigKey& key,
531                                               const StatsdConfig& config, bool modularUpdate) {
532     VLOG("Updated configuration for key %s", key.ToString().c_str());
533     // Create new config if this is not a modular update or if this is a new config.
534     const auto& it = mMetricsManagers.find(key);
535     bool configValid = false;
536     if (!modularUpdate || it == mMetricsManagers.end()) {
537         sp<MetricsManager> newMetricsManager =
538                 new MetricsManager(key, config, mTimeBaseNs, timestampNs, mUidMap, mPullerManager,
539                                    mAnomalyAlarmMonitor, mPeriodicAlarmMonitor);
540         configValid = newMetricsManager->isConfigValid();
541         if (configValid) {
542             newMetricsManager->init();
543             mUidMap->OnConfigUpdated(key);
544             newMetricsManager->refreshTtl(timestampNs);
545             mMetricsManagers[key] = newMetricsManager;
546             VLOG("StatsdConfig valid");
547         }
548     } else {
549         // Preserve the existing MetricsManager, update necessary components and metadata in place.
550         configValid = it->second->updateConfig(config, mTimeBaseNs, timestampNs,
551                                                mAnomalyAlarmMonitor, mPeriodicAlarmMonitor);
552         if (configValid) {
553             mUidMap->OnConfigUpdated(key);
554         }
555     }
556     if (!configValid) {
557         // If there is any error in the config, don't use it.
558         // Remove any existing config with the same key.
559         ALOGE("StatsdConfig NOT valid");
560         mMetricsManagers.erase(key);
561     }
562 }
563 
GetMetricsSize(const ConfigKey & key) const564 size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const {
565     std::lock_guard<std::mutex> lock(mMetricsMutex);
566     auto it = mMetricsManagers.find(key);
567     if (it == mMetricsManagers.end()) {
568         ALOGW("Config source %s does not exist", key.ToString().c_str());
569         return 0;
570     }
571     return it->second->byteSize();
572 }
573 
dumpStates(int out,bool verbose)574 void StatsLogProcessor::dumpStates(int out, bool verbose) {
575     std::lock_guard<std::mutex> lock(mMetricsMutex);
576     FILE* fout = fdopen(out, "w");
577     if (fout == NULL) {
578         return;
579     }
580     fprintf(fout, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size());
581     for (auto metricsManager : mMetricsManagers) {
582         metricsManager.second->dumpStates(fout, verbose);
583     }
584 
585     fclose(fout);
586 }
587 
588 /*
589  * onDumpReport dumps serialized ConfigMetricsReportList into proto.
590  */
onDumpReport(const ConfigKey & key,const int64_t dumpTimeStampNs,const bool include_current_partial_bucket,const bool erase_data,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,ProtoOutputStream * proto)591 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
592                                      const bool include_current_partial_bucket,
593                                      const bool erase_data,
594                                      const DumpReportReason dumpReportReason,
595                                      const DumpLatency dumpLatency,
596                                      ProtoOutputStream* proto) {
597     std::lock_guard<std::mutex> lock(mMetricsMutex);
598 
599     // Start of ConfigKey.
600     uint64_t configKeyToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY);
601     proto->write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid());
602     proto->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId());
603     proto->end(configKeyToken);
604     // End of ConfigKey.
605 
606     bool keepFile = false;
607     auto it = mMetricsManagers.find(key);
608     if (it != mMetricsManagers.end() && it->second->shouldPersistLocalHistory()) {
609         keepFile = true;
610     }
611 
612     // Then, check stats-data directory to see there's any file containing
613     // ConfigMetricsReport from previous shutdowns to concatenate to reports.
614     StorageManager::appendConfigMetricsReport(
615             key, proto, erase_data && !keepFile /* should remove file after appending it */,
616             dumpReportReason == ADB_DUMP /*if caller is adb*/);
617 
618     if (it != mMetricsManagers.end()) {
619         // This allows another broadcast to be sent within the rate-limit period if we get close to
620         // filling the buffer again soon.
621         mLastBroadcastTimes.erase(key);
622 
623         vector<uint8_t> buffer;
624         onConfigMetricsReportLocked(key, dumpTimeStampNs, include_current_partial_bucket,
625                                     erase_data, dumpReportReason, dumpLatency,
626                                     false /* is this data going to be saved on disk */, &buffer);
627         proto->write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS,
628                      reinterpret_cast<char*>(buffer.data()), buffer.size());
629     } else {
630         ALOGW("Config source %s does not exist", key.ToString().c_str());
631     }
632 }
633 
634 /*
635  * onDumpReport dumps serialized ConfigMetricsReportList into outData.
636  */
onDumpReport(const ConfigKey & key,const int64_t dumpTimeStampNs,const bool include_current_partial_bucket,const bool erase_data,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,vector<uint8_t> * outData)637 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
638                                      const bool include_current_partial_bucket,
639                                      const bool erase_data,
640                                      const DumpReportReason dumpReportReason,
641                                      const DumpLatency dumpLatency,
642                                      vector<uint8_t>* outData) {
643     ProtoOutputStream proto;
644     onDumpReport(key, dumpTimeStampNs, include_current_partial_bucket, erase_data,
645                  dumpReportReason, dumpLatency, &proto);
646 
647     if (outData != nullptr) {
648         flushProtoToBuffer(proto, outData);
649         VLOG("output data size %zu", outData->size());
650     }
651 
652     StatsdStats::getInstance().noteMetricsReportSent(key, proto.size());
653 }
654 
655 /*
656  * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData.
657  */
onConfigMetricsReportLocked(const ConfigKey & key,const int64_t dumpTimeStampNs,const bool include_current_partial_bucket,const bool erase_data,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,const bool dataSavedOnDisk,vector<uint8_t> * buffer)658 void StatsLogProcessor::onConfigMetricsReportLocked(
659         const ConfigKey& key, const int64_t dumpTimeStampNs,
660         const bool include_current_partial_bucket, const bool erase_data,
661         const DumpReportReason dumpReportReason, const DumpLatency dumpLatency,
662         const bool dataSavedOnDisk, vector<uint8_t>* buffer) {
663     // We already checked whether key exists in mMetricsManagers in
664     // WriteDataToDisk.
665     auto it = mMetricsManagers.find(key);
666     if (it == mMetricsManagers.end()) {
667         return;
668     }
669     int64_t lastReportTimeNs = it->second->getLastReportTimeNs();
670     int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs();
671 
672     std::set<string> str_set;
673 
674     ProtoOutputStream tempProto;
675     // First, fill in ConfigMetricsReport using current data on memory, which
676     // starts from filling in StatsLogReport's.
677     it->second->onDumpReport(dumpTimeStampNs, include_current_partial_bucket, erase_data,
678                              dumpLatency, &str_set, &tempProto);
679 
680     // Fill in UidMap if there is at least one metric to report.
681     // This skips the uid map if it's an empty config.
682     if (it->second->getNumMetrics() > 0) {
683         uint64_t uidMapToken = tempProto.start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP);
684         mUidMap->appendUidMap(
685                 dumpTimeStampNs, key, it->second->hashStringInReport() ? &str_set : nullptr,
686                 it->second->versionStringsInReport(), it->second->installerInReport(), &tempProto);
687         tempProto.end(uidMapToken);
688     }
689 
690     // Fill in the timestamps.
691     tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS,
692                     (long long)lastReportTimeNs);
693     tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS,
694                     (long long)dumpTimeStampNs);
695     tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS,
696                     (long long)lastReportWallClockNs);
697     tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS,
698                     (long long)getWallClockNs());
699     // Dump report reason
700     tempProto.write(FIELD_TYPE_INT32 | FIELD_ID_DUMP_REPORT_REASON, dumpReportReason);
701 
702     for (const auto& str : str_set) {
703         tempProto.write(FIELD_TYPE_STRING | FIELD_COUNT_REPEATED | FIELD_ID_STRINGS, str);
704     }
705 
706     flushProtoToBuffer(tempProto, buffer);
707 
708     // save buffer to disk if needed
709     if (erase_data && !dataSavedOnDisk && it->second->shouldPersistLocalHistory()) {
710         VLOG("save history to disk");
711         string file_name = StorageManager::getDataHistoryFileName((long)getWallClockSec(),
712                                                                   key.GetUid(), key.GetId());
713         StorageManager::writeFile(file_name.c_str(), buffer->data(), buffer->size());
714     }
715 }
716 
resetConfigsLocked(const int64_t timestampNs,const std::vector<ConfigKey> & configs)717 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs,
718                                            const std::vector<ConfigKey>& configs) {
719     for (const auto& key : configs) {
720         StatsdConfig config;
721         if (StorageManager::readConfigFromDisk(key, &config)) {
722             // Force a full update when resetting a config.
723             OnConfigUpdatedLocked(timestampNs, key, config, /*modularUpdate=*/false);
724             StatsdStats::getInstance().noteConfigReset(key);
725         } else {
726             ALOGE("Failed to read backup config from disk for : %s", key.ToString().c_str());
727             auto it = mMetricsManagers.find(key);
728             if (it != mMetricsManagers.end()) {
729                 it->second->refreshTtl(timestampNs);
730             }
731         }
732     }
733 }
734 
resetIfConfigTtlExpiredLocked(const int64_t eventTimeNs)735 void StatsLogProcessor::resetIfConfigTtlExpiredLocked(const int64_t eventTimeNs) {
736     std::vector<ConfigKey> configKeysTtlExpired;
737     for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
738         if (it->second != nullptr && !it->second->isInTtl(eventTimeNs)) {
739             configKeysTtlExpired.push_back(it->first);
740         }
741     }
742     if (configKeysTtlExpired.size() > 0) {
743         WriteDataToDiskLocked(CONFIG_RESET, NO_TIME_CONSTRAINTS, getElapsedRealtimeNs());
744         resetConfigsLocked(eventTimeNs, configKeysTtlExpired);
745     }
746 }
747 
OnConfigRemoved(const ConfigKey & key)748 void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
749     std::lock_guard<std::mutex> lock(mMetricsMutex);
750     auto it = mMetricsManagers.find(key);
751     if (it != mMetricsManagers.end()) {
752         WriteDataToDiskLocked(key, getElapsedRealtimeNs(), CONFIG_REMOVED,
753                               NO_TIME_CONSTRAINTS);
754         mMetricsManagers.erase(it);
755         mUidMap->OnConfigRemoved(key);
756     }
757     StatsdStats::getInstance().noteConfigRemoved(key);
758 
759     mLastBroadcastTimes.erase(key);
760 
761     int uid = key.GetUid();
762     bool lastConfigForUid = true;
763     for (auto it : mMetricsManagers) {
764         if (it.first.GetUid() == uid) {
765             lastConfigForUid = false;
766             break;
767         }
768     }
769     if (lastConfigForUid) {
770         mLastActivationBroadcastTimes.erase(uid);
771     }
772 
773     if (mMetricsManagers.empty()) {
774         mPullerManager->ForceClearPullerCache();
775     }
776 }
777 
flushIfNecessaryLocked(const ConfigKey & key,MetricsManager & metricsManager)778 void StatsLogProcessor::flushIfNecessaryLocked(const ConfigKey& key,
779                                                MetricsManager& metricsManager) {
780     int64_t elapsedRealtimeNs = getElapsedRealtimeNs();
781     auto lastCheckTime = mLastByteSizeTimes.find(key);
782     if (lastCheckTime != mLastByteSizeTimes.end()) {
783         if (elapsedRealtimeNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
784             return;
785         }
786     }
787 
788     // We suspect that the byteSize() computation is expensive, so we set a rate limit.
789     size_t totalBytes = metricsManager.byteSize();
790     mLastByteSizeTimes[key] = elapsedRealtimeNs;
791     bool requestDump = false;
792     if (totalBytes > StatsdStats::kMaxMetricsBytesPerConfig) {
793         // Too late. We need to start clearing data.
794         metricsManager.dropData(elapsedRealtimeNs);
795         StatsdStats::getInstance().noteDataDropped(key, totalBytes);
796         VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
797     } else if ((totalBytes > StatsdStats::kBytesPerConfigTriggerGetData) ||
798                (mOnDiskDataConfigs.find(key) != mOnDiskDataConfigs.end())) {
799         // Request to send a broadcast if:
800         // 1. in memory data > threshold   OR
801         // 2. config has old data report on disk.
802         requestDump = true;
803     }
804 
805     if (requestDump) {
806         // Send broadcast so that receivers can pull data.
807         auto lastBroadcastTime = mLastBroadcastTimes.find(key);
808         if (lastBroadcastTime != mLastBroadcastTimes.end()) {
809             if (elapsedRealtimeNs - lastBroadcastTime->second <
810                     StatsdStats::kMinBroadcastPeriodNs) {
811                 VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
812                 return;
813             }
814         }
815         if (mSendBroadcast(key)) {
816             mOnDiskDataConfigs.erase(key);
817             VLOG("StatsD triggered data fetch for %s", key.ToString().c_str());
818             mLastBroadcastTimes[key] = elapsedRealtimeNs;
819             StatsdStats::getInstance().noteBroadcastSent(key);
820         }
821     }
822 }
823 
WriteDataToDiskLocked(const ConfigKey & key,const int64_t timestampNs,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency)824 void StatsLogProcessor::WriteDataToDiskLocked(const ConfigKey& key,
825                                               const int64_t timestampNs,
826                                               const DumpReportReason dumpReportReason,
827                                               const DumpLatency dumpLatency) {
828     if (mMetricsManagers.find(key) == mMetricsManagers.end() ||
829         !mMetricsManagers.find(key)->second->shouldWriteToDisk()) {
830         return;
831     }
832     vector<uint8_t> buffer;
833     onConfigMetricsReportLocked(key, timestampNs, true /* include_current_partial_bucket*/,
834                                 true /* erase_data */, dumpReportReason, dumpLatency, true,
835                                 &buffer);
836     string file_name =
837             StorageManager::getDataFileName((long)getWallClockSec(), key.GetUid(), key.GetId());
838     StorageManager::writeFile(file_name.c_str(), buffer.data(), buffer.size());
839 
840     // We were able to write the ConfigMetricsReport to disk, so we should trigger collection ASAP.
841     mOnDiskDataConfigs.insert(key);
842 }
843 
SaveActiveConfigsToDisk(int64_t currentTimeNs)844 void StatsLogProcessor::SaveActiveConfigsToDisk(int64_t currentTimeNs) {
845     std::lock_guard<std::mutex> lock(mMetricsMutex);
846     const int64_t timeNs = getElapsedRealtimeNs();
847     // Do not write to disk if we already have in the last few seconds.
848     if (static_cast<unsigned long long> (timeNs) <
849             mLastActiveMetricsWriteNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
850         ALOGI("Statsd skipping writing active metrics to disk. Already wrote data in last %d seconds",
851                 WRITE_DATA_COOL_DOWN_SEC);
852         return;
853     }
854     mLastActiveMetricsWriteNs = timeNs;
855 
856     ProtoOutputStream proto;
857     WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, DEVICE_SHUTDOWN, &proto);
858 
859     string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
860     StorageManager::deleteFile(file_name.c_str());
861     android::base::unique_fd fd(
862             open(file_name.c_str(), O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR));
863     if (fd == -1) {
864         ALOGE("Attempt to write %s but failed", file_name.c_str());
865         return;
866     }
867     proto.flush(fd.get());
868 }
869 
SaveMetadataToDisk(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)870 void StatsLogProcessor::SaveMetadataToDisk(int64_t currentWallClockTimeNs,
871                                            int64_t systemElapsedTimeNs) {
872     std::lock_guard<std::mutex> lock(mMetricsMutex);
873     // Do not write to disk if we already have in the last few seconds.
874     if (static_cast<unsigned long long> (systemElapsedTimeNs) <
875             mLastMetadataWriteNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
876         ALOGI("Statsd skipping writing metadata to disk. Already wrote data in last %d seconds",
877                 WRITE_DATA_COOL_DOWN_SEC);
878         return;
879     }
880     mLastMetadataWriteNs = systemElapsedTimeNs;
881 
882     metadata::StatsMetadataList metadataList;
883     WriteMetadataToProtoLocked(
884             currentWallClockTimeNs, systemElapsedTimeNs, &metadataList);
885 
886     string file_name = StringPrintf("%s/metadata", STATS_METADATA_DIR);
887     StorageManager::deleteFile(file_name.c_str());
888 
889     if (metadataList.stats_metadata_size() == 0) {
890         // Skip the write if we have nothing to write.
891         return;
892     }
893 
894     std::string data;
895     metadataList.SerializeToString(&data);
896     StorageManager::writeFile(file_name.c_str(), data.c_str(), data.size());
897 }
898 
WriteMetadataToProto(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs,metadata::StatsMetadataList * metadataList)899 void StatsLogProcessor::WriteMetadataToProto(int64_t currentWallClockTimeNs,
900                                              int64_t systemElapsedTimeNs,
901                                              metadata::StatsMetadataList* metadataList) {
902     std::lock_guard<std::mutex> lock(mMetricsMutex);
903     WriteMetadataToProtoLocked(currentWallClockTimeNs, systemElapsedTimeNs, metadataList);
904 }
905 
WriteMetadataToProtoLocked(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs,metadata::StatsMetadataList * metadataList)906 void StatsLogProcessor::WriteMetadataToProtoLocked(int64_t currentWallClockTimeNs,
907                                                    int64_t systemElapsedTimeNs,
908                                                    metadata::StatsMetadataList* metadataList) {
909     for (const auto& pair : mMetricsManagers) {
910         const sp<MetricsManager>& metricsManager = pair.second;
911         metadata::StatsMetadata* statsMetadata = metadataList->add_stats_metadata();
912         bool metadataWritten = metricsManager->writeMetadataToProto(currentWallClockTimeNs,
913                 systemElapsedTimeNs, statsMetadata);
914         if (!metadataWritten) {
915             metadataList->mutable_stats_metadata()->RemoveLast();
916         }
917     }
918 }
919 
LoadMetadataFromDisk(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)920 void StatsLogProcessor::LoadMetadataFromDisk(int64_t currentWallClockTimeNs,
921                                              int64_t systemElapsedTimeNs) {
922     std::lock_guard<std::mutex> lock(mMetricsMutex);
923     string file_name = StringPrintf("%s/metadata", STATS_METADATA_DIR);
924     int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC);
925     if (-1 == fd) {
926         VLOG("Attempt to read %s but failed", file_name.c_str());
927         StorageManager::deleteFile(file_name.c_str());
928         return;
929     }
930     string content;
931     if (!android::base::ReadFdToString(fd, &content)) {
932         ALOGE("Attempt to read %s but failed", file_name.c_str());
933         close(fd);
934         StorageManager::deleteFile(file_name.c_str());
935         return;
936     }
937 
938     close(fd);
939 
940     metadata::StatsMetadataList statsMetadataList;
941     if (!statsMetadataList.ParseFromString(content)) {
942         ALOGE("Attempt to read %s but failed; failed to metadata", file_name.c_str());
943         StorageManager::deleteFile(file_name.c_str());
944         return;
945     }
946     SetMetadataStateLocked(statsMetadataList, currentWallClockTimeNs, systemElapsedTimeNs);
947     StorageManager::deleteFile(file_name.c_str());
948 }
949 
SetMetadataState(const metadata::StatsMetadataList & statsMetadataList,int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)950 void StatsLogProcessor::SetMetadataState(const metadata::StatsMetadataList& statsMetadataList,
951                                          int64_t currentWallClockTimeNs,
952                                          int64_t systemElapsedTimeNs) {
953     std::lock_guard<std::mutex> lock(mMetricsMutex);
954     SetMetadataStateLocked(statsMetadataList, currentWallClockTimeNs, systemElapsedTimeNs);
955 }
956 
SetMetadataStateLocked(const metadata::StatsMetadataList & statsMetadataList,int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)957 void StatsLogProcessor::SetMetadataStateLocked(
958         const metadata::StatsMetadataList& statsMetadataList,
959         int64_t currentWallClockTimeNs,
960         int64_t systemElapsedTimeNs) {
961     for (const metadata::StatsMetadata& metadata : statsMetadataList.stats_metadata()) {
962         ConfigKey key(metadata.config_key().uid(), metadata.config_key().config_id());
963         auto it = mMetricsManagers.find(key);
964         if (it == mMetricsManagers.end()) {
965             ALOGE("No config found for configKey %s", key.ToString().c_str());
966             continue;
967         }
968         VLOG("Setting metadata %s", key.ToString().c_str());
969         it->second->loadMetadata(metadata, currentWallClockTimeNs, systemElapsedTimeNs);
970     }
971     VLOG("Successfully loaded %d metadata.", statsMetadataList.stats_metadata_size());
972 }
973 
WriteActiveConfigsToProtoOutputStream(int64_t currentTimeNs,const DumpReportReason reason,ProtoOutputStream * proto)974 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStream(
975         int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) {
976     std::lock_guard<std::mutex> lock(mMetricsMutex);
977     WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, reason, proto);
978 }
979 
WriteActiveConfigsToProtoOutputStreamLocked(int64_t currentTimeNs,const DumpReportReason reason,ProtoOutputStream * proto)980 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStreamLocked(
981         int64_t currentTimeNs,  const DumpReportReason reason, ProtoOutputStream* proto) {
982     for (const auto& pair : mMetricsManagers) {
983         const sp<MetricsManager>& metricsManager = pair.second;
984         uint64_t configToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED |
985                                                      FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG);
986         metricsManager->writeActiveConfigToProtoOutputStream(currentTimeNs, reason, proto);
987         proto->end(configToken);
988     }
989 }
LoadActiveConfigsFromDisk()990 void StatsLogProcessor::LoadActiveConfigsFromDisk() {
991     std::lock_guard<std::mutex> lock(mMetricsMutex);
992     string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
993     int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC);
994     if (-1 == fd) {
995         VLOG("Attempt to read %s but failed", file_name.c_str());
996         StorageManager::deleteFile(file_name.c_str());
997         return;
998     }
999     string content;
1000     if (!android::base::ReadFdToString(fd, &content)) {
1001         ALOGE("Attempt to read %s but failed", file_name.c_str());
1002         close(fd);
1003         StorageManager::deleteFile(file_name.c_str());
1004         return;
1005     }
1006 
1007     close(fd);
1008 
1009     ActiveConfigList activeConfigList;
1010     if (!activeConfigList.ParseFromString(content)) {
1011         ALOGE("Attempt to read %s but failed; failed to load active configs", file_name.c_str());
1012         StorageManager::deleteFile(file_name.c_str());
1013         return;
1014     }
1015     // Passing in mTimeBaseNs only works as long as we only load from disk is when statsd starts.
1016     SetConfigsActiveStateLocked(activeConfigList, mTimeBaseNs);
1017     StorageManager::deleteFile(file_name.c_str());
1018 }
1019 
SetConfigsActiveState(const ActiveConfigList & activeConfigList,int64_t currentTimeNs)1020 void StatsLogProcessor::SetConfigsActiveState(const ActiveConfigList& activeConfigList,
1021                                                     int64_t currentTimeNs) {
1022     std::lock_guard<std::mutex> lock(mMetricsMutex);
1023     SetConfigsActiveStateLocked(activeConfigList, currentTimeNs);
1024 }
1025 
SetConfigsActiveStateLocked(const ActiveConfigList & activeConfigList,int64_t currentTimeNs)1026 void StatsLogProcessor::SetConfigsActiveStateLocked(const ActiveConfigList& activeConfigList,
1027                                                     int64_t currentTimeNs) {
1028     for (int i = 0; i < activeConfigList.config_size(); i++) {
1029         const auto& config = activeConfigList.config(i);
1030         ConfigKey key(config.uid(), config.id());
1031         auto it = mMetricsManagers.find(key);
1032         if (it == mMetricsManagers.end()) {
1033             ALOGE("No config found for config %s", key.ToString().c_str());
1034             continue;
1035         }
1036         VLOG("Setting active config %s", key.ToString().c_str());
1037         it->second->loadActiveConfig(config, currentTimeNs);
1038     }
1039     VLOG("Successfully loaded %d active configs.", activeConfigList.config_size());
1040 }
1041 
WriteDataToDiskLocked(const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,const int64_t elapsedRealtimeNs)1042 void StatsLogProcessor::WriteDataToDiskLocked(const DumpReportReason dumpReportReason,
1043                                               const DumpLatency dumpLatency,
1044                                               const int64_t elapsedRealtimeNs) {
1045     // Do not write to disk if we already have in the last few seconds.
1046     // This is to avoid overwriting files that would have the same name if we
1047     //   write twice in the same second.
1048     if (static_cast<unsigned long long>(elapsedRealtimeNs) <
1049         mLastWriteTimeNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
1050         ALOGI("Statsd skipping writing data to disk. Already wrote data in last %d seconds",
1051                 WRITE_DATA_COOL_DOWN_SEC);
1052         return;
1053     }
1054     mLastWriteTimeNs = elapsedRealtimeNs;
1055     for (auto& pair : mMetricsManagers) {
1056         WriteDataToDiskLocked(pair.first, elapsedRealtimeNs, dumpReportReason, dumpLatency);
1057     }
1058 }
1059 
WriteDataToDisk(const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,const int64_t elapsedRealtimeNs)1060 void StatsLogProcessor::WriteDataToDisk(const DumpReportReason dumpReportReason,
1061                                         const DumpLatency dumpLatency,
1062                                         const int64_t elapsedRealtimeNs) {
1063     std::lock_guard<std::mutex> lock(mMetricsMutex);
1064     WriteDataToDiskLocked(dumpReportReason, dumpLatency, elapsedRealtimeNs);
1065 }
1066 
informPullAlarmFired(const int64_t timestampNs)1067 void StatsLogProcessor::informPullAlarmFired(const int64_t timestampNs) {
1068     std::lock_guard<std::mutex> lock(mMetricsMutex);
1069     mPullerManager->OnAlarmFired(timestampNs);
1070 }
1071 
getLastReportTimeNs(const ConfigKey & key)1072 int64_t StatsLogProcessor::getLastReportTimeNs(const ConfigKey& key) {
1073     auto it = mMetricsManagers.find(key);
1074     if (it == mMetricsManagers.end()) {
1075         return 0;
1076     } else {
1077         return it->second->getLastReportTimeNs();
1078     }
1079 }
1080 
notifyAppUpgrade(const int64_t & eventTimeNs,const string & apk,const int uid,const int64_t version)1081 void StatsLogProcessor::notifyAppUpgrade(const int64_t& eventTimeNs, const string& apk,
1082                                          const int uid, const int64_t version) {
1083     std::lock_guard<std::mutex> lock(mMetricsMutex);
1084     VLOG("Received app upgrade");
1085     StateManager::getInstance().notifyAppChanged(apk, mUidMap);
1086     for (const auto& it : mMetricsManagers) {
1087         it.second->notifyAppUpgrade(eventTimeNs, apk, uid, version);
1088     }
1089 }
1090 
notifyAppRemoved(const int64_t & eventTimeNs,const string & apk,const int uid)1091 void StatsLogProcessor::notifyAppRemoved(const int64_t& eventTimeNs, const string& apk,
1092                                          const int uid) {
1093     std::lock_guard<std::mutex> lock(mMetricsMutex);
1094     VLOG("Received app removed");
1095     StateManager::getInstance().notifyAppChanged(apk, mUidMap);
1096     for (const auto& it : mMetricsManagers) {
1097         it.second->notifyAppRemoved(eventTimeNs, apk, uid);
1098     }
1099 }
1100 
onUidMapReceived(const int64_t & eventTimeNs)1101 void StatsLogProcessor::onUidMapReceived(const int64_t& eventTimeNs) {
1102     std::lock_guard<std::mutex> lock(mMetricsMutex);
1103     VLOG("Received uid map");
1104     StateManager::getInstance().updateLogSources(mUidMap);
1105     for (const auto& it : mMetricsManagers) {
1106         it.second->onUidMapReceived(eventTimeNs);
1107     }
1108 }
1109 
onStatsdInitCompleted(const int64_t & elapsedTimeNs)1110 void StatsLogProcessor::onStatsdInitCompleted(const int64_t& elapsedTimeNs) {
1111     std::lock_guard<std::mutex> lock(mMetricsMutex);
1112     VLOG("Received boot completed signal");
1113     for (const auto& it : mMetricsManagers) {
1114         it.second->onStatsdInitCompleted(elapsedTimeNs);
1115     }
1116 }
1117 
noteOnDiskData(const ConfigKey & key)1118 void StatsLogProcessor::noteOnDiskData(const ConfigKey& key) {
1119     std::lock_guard<std::mutex> lock(mMetricsMutex);
1120     mOnDiskDataConfigs.insert(key);
1121 }
1122 
setAnomalyAlarm(const int64_t elapsedTimeMillis)1123 void StatsLogProcessor::setAnomalyAlarm(const int64_t elapsedTimeMillis) {
1124     std::lock_guard<std::mutex> lock(mAnomalyAlarmMutex);
1125     mNextAnomalyAlarmTime = elapsedTimeMillis;
1126 }
1127 
cancelAnomalyAlarm()1128 void StatsLogProcessor::cancelAnomalyAlarm() {
1129     std::lock_guard<std::mutex> lock(mAnomalyAlarmMutex);
1130     mNextAnomalyAlarmTime = 0;
1131 }
1132 
informAnomalyAlarmFiredLocked(const int64_t elapsedTimeMillis)1133 void StatsLogProcessor::informAnomalyAlarmFiredLocked(const int64_t elapsedTimeMillis) {
1134     VLOG("StatsService::informAlarmForSubscriberTriggeringFired was called");
1135     std::unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet =
1136             mAnomalyAlarmMonitor->popSoonerThan(static_cast<uint32_t>(elapsedTimeMillis / 1000));
1137     if (alarmSet.size() > 0) {
1138         VLOG("Found periodic alarm fired.");
1139         processFiredAnomalyAlarmsLocked(MillisToNano(elapsedTimeMillis), alarmSet);
1140     } else {
1141         ALOGW("Cannot find an periodic alarm that fired. Perhaps it was recently cancelled.");
1142     }
1143 }
1144 
1145 }  // namespace statsd
1146 }  // namespace os
1147 }  // namespace android
1148