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