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