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