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 #include "utils/api_tracing.h"
40
41 using namespace android;
42 using android::base::StringPrintf;
43 using android::util::FIELD_COUNT_REPEATED;
44 using android::util::FIELD_TYPE_BOOL;
45 using android::util::FIELD_TYPE_FLOAT;
46 using android::util::FIELD_TYPE_INT32;
47 using android::util::FIELD_TYPE_INT64;
48 using android::util::FIELD_TYPE_MESSAGE;
49 using android::util::FIELD_TYPE_STRING;
50 using android::util::ProtoOutputStream;
51 using std::vector;
52
53 namespace android {
54 namespace os {
55 namespace statsd {
56
57 using aidl::android::os::IStatsQueryCallback;
58
59 // for ConfigMetricsReportList
60 const int FIELD_ID_CONFIG_KEY = 1;
61 const int FIELD_ID_REPORTS = 2;
62 // for ConfigKey
63 const int FIELD_ID_UID = 1;
64 const int FIELD_ID_ID = 2;
65 const int FIELD_ID_REPORT_NUMBER = 3;
66 const int FIELD_ID_STATSD_STATS_ID = 4;
67 // for ConfigMetricsReport
68 // const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp
69 const int FIELD_ID_UID_MAP = 2;
70 const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3;
71 const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4;
72 const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5;
73 const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6;
74 const int FIELD_ID_DUMP_REPORT_REASON = 8;
75 const int FIELD_ID_STRINGS = 9;
76 const int FIELD_ID_DATA_CORRUPTED_REASON = 11;
77 const int FIELD_ID_ESTIMATED_DATA_BYTES = 12;
78
79 // for ActiveConfigList
80 const int FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG = 1;
81
82 // for permissions checks
83 constexpr const char* kPermissionDump = "android.permission.DUMP";
84 constexpr const char* kPermissionUsage = "android.permission.PACKAGE_USAGE_STATS";
85
86 #define NS_PER_HOUR 3600 * NS_PER_SEC
87
88 #define STATS_ACTIVE_METRIC_DIR "/data/misc/stats-active-metric"
89 #define STATS_METADATA_DIR "/data/misc/stats-metadata"
90
91 // Cool down period for writing data to disk to avoid overwriting files.
92 #define WRITE_DATA_COOL_DOWN_SEC 15
93
94 namespace {
95
getOnLogEventCallName(int32_t tagId)96 const char* getOnLogEventCallName(int32_t tagId) {
97 static std::string name;
98 // to avoid new string allocation on each call
99 name.reserve(30);
100 name = "OnLogEvent-" + std::to_string(tagId);
101 return name.c_str();
102 }
103
104 } // namespace
105
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,const std::function<void (const ConfigKey &,const string &,const vector<int64_t> &)> & sendRestrictedMetricsBroadcast,const std::shared_ptr<LogEventFilter> & logEventFilter)106 StatsLogProcessor::StatsLogProcessor(
107 const sp<UidMap>& uidMap, const sp<StatsPullerManager>& pullerManager,
108 const sp<AlarmMonitor>& anomalyAlarmMonitor, const sp<AlarmMonitor>& periodicAlarmMonitor,
109 const int64_t timeBaseNs, const std::function<bool(const ConfigKey&)>& sendBroadcast,
110 const std::function<bool(const int&, const vector<int64_t>&)>& activateBroadcast,
111 const std::function<void(const ConfigKey&, const string&, const vector<int64_t>&)>&
112 sendRestrictedMetricsBroadcast,
113 const std::shared_ptr<LogEventFilter>& logEventFilter)
114 : mLastTtlTime(0),
115 mLastFlushRestrictedTime(0),
116 mLastDbGuardrailEnforcementTime(0),
117 mUidMap(uidMap),
118 mPullerManager(pullerManager),
119 mAnomalyAlarmMonitor(anomalyAlarmMonitor),
120 mPeriodicAlarmMonitor(periodicAlarmMonitor),
121 mLogEventFilter(logEventFilter),
122 mSendBroadcast(sendBroadcast),
123 mSendActivationBroadcast(activateBroadcast),
124 mSendRestrictedMetricsBroadcast(sendRestrictedMetricsBroadcast),
125 mTimeBaseNs(timeBaseNs),
126 mLargestTimestampSeen(0),
127 mLastTimestampSeen(0) {
128 mPullerManager->ForceClearPullerCache();
129 StateManager::getInstance().updateLogSources(uidMap);
130 // It is safe called locked version at constructor - no concurrent access possible
131 updateLogEventFilterLocked();
132 }
133
~StatsLogProcessor()134 StatsLogProcessor::~StatsLogProcessor() {
135 }
136
flushProtoToBuffer(ProtoOutputStream & proto,vector<uint8_t> * outData)137 static void flushProtoToBuffer(ProtoOutputStream& proto, vector<uint8_t>* outData) {
138 outData->clear();
139 outData->resize(proto.size());
140 size_t pos = 0;
141 sp<android::util::ProtoReader> reader = proto.data();
142 while (reader->readBuffer() != NULL) {
143 size_t toRead = reader->currentToRead();
144 std::memcpy(&((*outData)[pos]), reader->readBuffer(), toRead);
145 pos += toRead;
146 reader->move(toRead);
147 }
148 }
149
processFiredAnomalyAlarmsLocked(const int64_t timestampNs,unordered_set<sp<const InternalAlarm>,SpHash<InternalAlarm>> & alarmSet)150 void StatsLogProcessor::processFiredAnomalyAlarmsLocked(
151 const int64_t timestampNs,
152 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>>& alarmSet) {
153 for (const auto& itr : mMetricsManagers) {
154 itr.second->onAnomalyAlarmFired(timestampNs, alarmSet);
155 }
156 }
onPeriodicAlarmFired(const int64_t timestampNs,unordered_set<sp<const InternalAlarm>,SpHash<InternalAlarm>> & alarmSet)157 void StatsLogProcessor::onPeriodicAlarmFired(
158 const int64_t timestampNs,
159 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>>& alarmSet) {
160 std::lock_guard<std::mutex> lock(mMetricsMutex);
161 for (const auto& itr : mMetricsManagers) {
162 itr.second->onPeriodicAlarmFired(timestampNs, alarmSet);
163 }
164 }
165
mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent * event) const166 void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const {
167 if (std::pair<size_t, size_t> indexRange; event->hasAttributionChain(&indexRange)) {
168 vector<FieldValue>* const fieldValues = event->getMutableValues();
169 for (size_t i = indexRange.first; i <= indexRange.second; i++) {
170 FieldValue& fieldValue = fieldValues->at(i);
171 if (isAttributionUidField(fieldValue)) {
172 const int hostUid = mUidMap->getHostUidOrSelf(fieldValue.mValue.int_value);
173 fieldValue.mValue.setInt(hostUid);
174 }
175 }
176 } else {
177 mapIsolatedUidsToHostUidInLogEvent(mUidMap, *event);
178 }
179 }
180
onIsolatedUidChangedEventLocked(const LogEvent & event)181 void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
182 status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR;
183 bool is_create = event.GetBool(3, &err);
184 auto parent_uid = int(event.GetLong(1, &err2));
185 auto isolated_uid = int(event.GetLong(2, &err3));
186 if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) {
187 if (is_create) {
188 mUidMap->assignIsolatedUid(isolated_uid, parent_uid);
189 } else {
190 mUidMap->removeIsolatedUid(isolated_uid);
191 }
192 } else {
193 ALOGE("Failed to parse uid in the isolated uid change event.");
194 }
195 }
196
onBinaryPushStateChangedEventLocked(LogEvent * event)197 void StatsLogProcessor::onBinaryPushStateChangedEventLocked(LogEvent* event) {
198 pid_t pid = event->GetPid();
199 uid_t uid = event->GetUid();
200 if (!checkPermissionForIds(kPermissionDump, pid, uid) ||
201 !checkPermissionForIds(kPermissionUsage, pid, uid)) {
202 return;
203 }
204 // The Get* functions don't modify the status on success, they only write in
205 // failure statuses, so we can use one status variable for all calls then
206 // check if it is no longer NO_ERROR.
207 status_t err = NO_ERROR;
208 InstallTrainInfo trainInfo;
209 trainInfo.trainName = string(event->GetString(1 /*train name field id*/, &err));
210 trainInfo.trainVersionCode = event->GetLong(2 /*train version field id*/, &err);
211 trainInfo.requiresStaging = event->GetBool(3 /*requires staging field id*/, &err);
212 trainInfo.rollbackEnabled = event->GetBool(4 /*rollback enabled field id*/, &err);
213 trainInfo.requiresLowLatencyMonitor =
214 event->GetBool(5 /*requires low latency monitor field id*/, &err);
215 trainInfo.status = int32_t(event->GetLong(6 /*state field id*/, &err));
216 std::vector<uint8_t> trainExperimentIdBytes =
217 event->GetStorage(7 /*experiment ids field id*/, &err);
218 bool is_rollback = event->GetBool(10 /*is rollback field id*/, &err);
219
220 if (err != NO_ERROR) {
221 ALOGE("Failed to parse fields in binary push state changed log event");
222 return;
223 }
224 ExperimentIds trainExperimentIds;
225 if (!trainExperimentIds.ParseFromArray(trainExperimentIdBytes.data(),
226 trainExperimentIdBytes.size())) {
227 ALOGE("Failed to parse experimentids in binary push state changed.");
228 return;
229 }
230 trainInfo.experimentIds = {trainExperimentIds.experiment_id().begin(),
231 trainExperimentIds.experiment_id().end()};
232
233 // Update the train info on disk and get any data the logevent is missing.
234 getAndUpdateTrainInfoOnDisk(is_rollback, &trainInfo);
235
236 std::vector<uint8_t> trainExperimentIdProto;
237 writeExperimentIdsToProto(trainInfo.experimentIds, &trainExperimentIdProto);
238 int32_t userId = multiuser_get_user_id(uid);
239
240 event->updateValue(2 /*train version field id*/, trainInfo.trainVersionCode, LONG);
241 event->updateValue(7 /*experiment ids field id*/, trainExperimentIdProto, STORAGE);
242 event->updateValue(8 /*user id field id*/, userId, INT);
243
244 // If this event is a rollback event, then the following bits in the event
245 // are invalid and we will need to update them with the values we pulled
246 // from disk.
247 if (is_rollback) {
248 int bit = trainInfo.requiresStaging ? 1 : 0;
249 event->updateValue(3 /*requires staging field id*/, bit, INT);
250 bit = trainInfo.rollbackEnabled ? 1 : 0;
251 event->updateValue(4 /*rollback enabled field id*/, bit, INT);
252 bit = trainInfo.requiresLowLatencyMonitor ? 1 : 0;
253 event->updateValue(5 /*requires low latency monitor field id*/, bit, INT);
254 }
255 }
256
getAndUpdateTrainInfoOnDisk(bool is_rollback,InstallTrainInfo * trainInfo)257 void StatsLogProcessor::getAndUpdateTrainInfoOnDisk(bool is_rollback,
258 InstallTrainInfo* trainInfo) {
259 // If the train name is empty, we don't know which train to attribute the
260 // event to, so return early.
261 if (trainInfo->trainName.empty()) {
262 return;
263 }
264 bool readTrainInfoSuccess = false;
265 InstallTrainInfo trainInfoOnDisk;
266 readTrainInfoSuccess = StorageManager::readTrainInfo(trainInfo->trainName, trainInfoOnDisk);
267
268 bool resetExperimentIds = false;
269 if (readTrainInfoSuccess) {
270 // Keep the old train version if we received an empty version.
271 if (trainInfo->trainVersionCode == -1) {
272 trainInfo->trainVersionCode = trainInfoOnDisk.trainVersionCode;
273 } else if (trainInfo->trainVersionCode != trainInfoOnDisk.trainVersionCode) {
274 // Reset experiment ids if we receive a new non-empty train version.
275 resetExperimentIds = true;
276 }
277
278 // Reset if we received a different experiment id.
279 if (!trainInfo->experimentIds.empty() &&
280 (trainInfoOnDisk.experimentIds.empty() ||
281 trainInfo->experimentIds.at(0) != trainInfoOnDisk.experimentIds[0])) {
282 resetExperimentIds = true;
283 }
284 }
285
286 // Find the right experiment IDs
287 if ((!resetExperimentIds || is_rollback) && readTrainInfoSuccess) {
288 trainInfo->experimentIds = trainInfoOnDisk.experimentIds;
289 }
290
291 if (!trainInfo->experimentIds.empty()) {
292 int64_t firstId = trainInfo->experimentIds.at(0);
293 auto& ids = trainInfo->experimentIds;
294 switch (trainInfo->status) {
295 case util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALL_SUCCESS:
296 if (find(ids.begin(), ids.end(), firstId + 1) == ids.end()) {
297 ids.push_back(firstId + 1);
298 }
299 break;
300 case util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_INITIATED:
301 if (find(ids.begin(), ids.end(), firstId + 2) == ids.end()) {
302 ids.push_back(firstId + 2);
303 }
304 break;
305 case util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_SUCCESS:
306 if (find(ids.begin(), ids.end(), firstId + 3) == ids.end()) {
307 ids.push_back(firstId + 3);
308 }
309 break;
310 }
311 }
312
313 // If this event is a rollback event, the following fields are invalid and
314 // need to be replaced by the fields stored to disk.
315 if (is_rollback) {
316 trainInfo->requiresStaging = trainInfoOnDisk.requiresStaging;
317 trainInfo->rollbackEnabled = trainInfoOnDisk.rollbackEnabled;
318 trainInfo->requiresLowLatencyMonitor = trainInfoOnDisk.requiresLowLatencyMonitor;
319 }
320
321 StorageManager::writeTrainInfo(*trainInfo);
322 }
323
onWatchdogRollbackOccurredLocked(LogEvent * event)324 void StatsLogProcessor::onWatchdogRollbackOccurredLocked(LogEvent* event) {
325 pid_t pid = event->GetPid();
326 uid_t uid = event->GetUid();
327 if (!checkPermissionForIds(kPermissionDump, pid, uid) ||
328 !checkPermissionForIds(kPermissionUsage, pid, uid)) {
329 return;
330 }
331 // The Get* functions don't modify the status on success, they only write in
332 // failure statuses, so we can use one status variable for all calls then
333 // check if it is no longer NO_ERROR.
334 status_t err = NO_ERROR;
335 int32_t rollbackType = int32_t(event->GetInt(1 /*rollback type field id*/, &err));
336 string packageName = string(event->GetString(2 /*package name field id*/, &err));
337
338 if (err != NO_ERROR) {
339 ALOGE("Failed to parse fields in watchdog rollback occurred log event");
340 return;
341 }
342
343 vector<int64_t> experimentIds =
344 processWatchdogRollbackOccurred(rollbackType, packageName);
345 vector<uint8_t> experimentIdProto;
346 writeExperimentIdsToProto(experimentIds, &experimentIdProto);
347
348 event->updateValue(6 /*experiment ids field id*/, experimentIdProto, STORAGE);
349 }
350
processWatchdogRollbackOccurred(const int32_t rollbackTypeIn,const string & packageNameIn)351 vector<int64_t> StatsLogProcessor::processWatchdogRollbackOccurred(const int32_t rollbackTypeIn,
352 const string& packageNameIn) {
353 // If the package name is empty, we can't attribute it to any train, so
354 // return early.
355 if (packageNameIn.empty()) {
356 return vector<int64_t>();
357 }
358 bool readTrainInfoSuccess = false;
359 InstallTrainInfo trainInfoOnDisk;
360 // We use the package name of the event as the train name.
361 readTrainInfoSuccess = StorageManager::readTrainInfo(packageNameIn, trainInfoOnDisk);
362
363 if (!readTrainInfoSuccess) {
364 return vector<int64_t>();
365 }
366
367 if (trainInfoOnDisk.experimentIds.empty()) {
368 return vector<int64_t>();
369 }
370
371 int64_t firstId = trainInfoOnDisk.experimentIds[0];
372 auto& ids = trainInfoOnDisk.experimentIds;
373 switch (rollbackTypeIn) {
374 case util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_INITIATE:
375 if (find(ids.begin(), ids.end(), firstId + 4) == ids.end()) {
376 ids.push_back(firstId + 4);
377 }
378 StorageManager::writeTrainInfo(trainInfoOnDisk);
379 break;
380 case util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS:
381 if (find(ids.begin(), ids.end(), firstId + 5) == ids.end()) {
382 ids.push_back(firstId + 5);
383 }
384 StorageManager::writeTrainInfo(trainInfoOnDisk);
385 break;
386 }
387
388 return trainInfoOnDisk.experimentIds;
389 }
390
resetConfigs()391 void StatsLogProcessor::resetConfigs() {
392 std::lock_guard<std::mutex> lock(mMetricsMutex);
393 resetConfigsLocked(getElapsedRealtimeNs());
394 }
395
resetConfigsLocked(const int64_t timestampNs)396 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) {
397 std::vector<ConfigKey> configKeys;
398 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
399 configKeys.push_back(it->first);
400 }
401 resetConfigsLocked(timestampNs, configKeys);
402 }
403
OnLogEvent(LogEvent * event)404 void StatsLogProcessor::OnLogEvent(LogEvent* event) {
405 ATRACE_NAME(getOnLogEventCallName(event->GetTagId()));
406 OnLogEvent(event, getElapsedRealtimeNs());
407 }
408
OnLogEvent(LogEvent * event,int64_t elapsedRealtimeNs)409 void StatsLogProcessor::OnLogEvent(LogEvent* event, int64_t elapsedRealtimeNs) {
410 const int64_t eventElapsedTimeNs = event->GetElapsedTimestampNs();
411 const int atomId = event->GetTagId();
412
413 if (!event->isValid()) {
414 StatsdStats::getInstance().noteAtomError(atomId);
415 return;
416 }
417
418 std::lock_guard<std::mutex> lock(mMetricsMutex);
419
420 // Hard-coded logic to update train info on disk and fill in any information
421 // this log event may be missing.
422 if (atomId == util::BINARY_PUSH_STATE_CHANGED) {
423 onBinaryPushStateChangedEventLocked(event);
424 }
425
426 // Hard-coded logic to update experiment ids on disk for certain rollback
427 // types and fill the rollback atom with experiment ids
428 if (atomId == util::WATCHDOG_ROLLBACK_OCCURRED) {
429 onWatchdogRollbackOccurredLocked(event);
430 }
431
432 if (mPrintAllLogs) {
433 ALOGI("%s", event->ToString().c_str());
434 }
435 resetIfConfigTtlExpiredLocked(eventElapsedTimeNs);
436
437 // Hard-coded logic to update the isolated uid's in the uid-map.
438 // The field numbers need to be currently updated by hand with atoms.proto
439 if (atomId == util::ISOLATED_UID_CHANGED) {
440 onIsolatedUidChangedEventLocked(*event);
441 } else {
442 // Map the isolated uid to host uid if necessary.
443 mapIsolatedUidToHostUidIfNecessaryLocked(event);
444 }
445
446 StateManager::getInstance().onLogEvent(*event);
447
448 if (mMetricsManagers.empty()) {
449 return;
450 }
451
452 bool fireAlarm = false;
453 {
454 std::lock_guard<std::mutex> anomalyLock(mAnomalyAlarmMutex);
455 if (mNextAnomalyAlarmTime != 0 &&
456 MillisToNano(mNextAnomalyAlarmTime) <= elapsedRealtimeNs) {
457 mNextAnomalyAlarmTime = 0;
458 VLOG("informing anomaly alarm at time %lld", (long long)elapsedRealtimeNs);
459 fireAlarm = true;
460 }
461 }
462 if (fireAlarm) {
463 informAnomalyAlarmFiredLocked(NanoToMillis(elapsedRealtimeNs));
464 }
465
466 const int64_t curTimeSec = NanoToSeconds(elapsedRealtimeNs);
467 if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
468 mPullerManager->ClearPullerCacheIfNecessary(curTimeSec * NS_PER_SEC);
469 mLastPullerCacheClearTimeSec = curTimeSec;
470 }
471
472 flushRestrictedDataIfNecessaryLocked(elapsedRealtimeNs);
473 enforceDataTtlsIfNecessaryLocked(getWallClockNs(), elapsedRealtimeNs);
474 enforceDbGuardrailsIfNecessaryLocked(getWallClockNs(), elapsedRealtimeNs);
475
476 if (!validateAppBreadcrumbEvent(*event)) {
477 return;
478 }
479
480 std::unordered_set<int> uidsWithActiveConfigsChanged;
481 std::unordered_map<int, std::vector<int64_t>> activeConfigsPerUid;
482
483 // pass the event to metrics managers.
484 for (auto& pair : mMetricsManagers) {
485 if (event->isRestricted() && !pair.second->hasRestrictedMetricsDelegate()) {
486 continue;
487 }
488 int uid = pair.first.GetUid();
489 int64_t configId = pair.first.GetId();
490 bool isPrevActive = pair.second->isActive();
491 pair.second->onLogEvent(*event);
492 bool isCurActive = pair.second->isActive();
493 // Map all active configs by uid.
494 if (isCurActive) {
495 auto activeConfigs = activeConfigsPerUid.find(uid);
496 if (activeConfigs != activeConfigsPerUid.end()) {
497 activeConfigs->second.push_back(configId);
498 } else {
499 vector<int64_t> newActiveConfigs;
500 newActiveConfigs.push_back(configId);
501 activeConfigsPerUid[uid] = newActiveConfigs;
502 }
503 }
504 // The activation state of this config changed.
505 if (isPrevActive != isCurActive) {
506 ALOGI("Active status changed for uid %d", uid);
507 uidsWithActiveConfigsChanged.insert(uid);
508 StatsdStats::getInstance().noteActiveStatusChanged(pair.first, isCurActive);
509 }
510 flushIfNecessaryLocked(pair.first, *(pair.second));
511 }
512
513 // Don't use the event timestamp for the guardrail.
514 for (int uid : uidsWithActiveConfigsChanged) {
515 // Send broadcast so that receivers can pull data.
516 auto lastBroadcastTime = mLastActivationBroadcastTimes.find(uid);
517 if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) {
518 if (elapsedRealtimeNs - lastBroadcastTime->second <
519 StatsdStats::kMinActivationBroadcastPeriodNs) {
520 StatsdStats::getInstance().noteActivationBroadcastGuardrailHit(uid);
521 ALOGI("StatsD would've sent an activation broadcast but the guardrail stopped us.");
522 return;
523 }
524 }
525 auto activeConfigs = activeConfigsPerUid.find(uid);
526 if (activeConfigs != activeConfigsPerUid.end()) {
527 if (mSendActivationBroadcast(uid, activeConfigs->second)) {
528 ALOGI("StatsD sent activation notice for uid %d", uid);
529 mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
530 }
531 } else {
532 std::vector<int64_t> emptyActiveConfigs;
533 if (mSendActivationBroadcast(uid, emptyActiveConfigs)) {
534 ALOGI("StatsD sent EMPTY activation notice for uid %d", uid);
535 mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
536 }
537 }
538 }
539 }
540
GetActiveConfigs(const int uid,vector<int64_t> & outActiveConfigs)541 void StatsLogProcessor::GetActiveConfigs(const int uid, vector<int64_t>& outActiveConfigs) {
542 std::lock_guard<std::mutex> lock(mMetricsMutex);
543 GetActiveConfigsLocked(uid, outActiveConfigs);
544 }
545
GetActiveConfigsLocked(const int uid,vector<int64_t> & outActiveConfigs)546 void StatsLogProcessor::GetActiveConfigsLocked(const int uid, vector<int64_t>& outActiveConfigs) {
547 outActiveConfigs.clear();
548 for (auto& pair : mMetricsManagers) {
549 if (pair.first.GetUid() == uid && pair.second->isActive()) {
550 outActiveConfigs.push_back(pair.first.GetId());
551 }
552 }
553 }
554
OnConfigUpdated(const int64_t timestampNs,const int64_t wallClockNs,const ConfigKey & key,const StatsdConfig & config,bool modularUpdate)555 void StatsLogProcessor::OnConfigUpdated(const int64_t timestampNs, const int64_t wallClockNs,
556 const ConfigKey& key, const StatsdConfig& config,
557 bool modularUpdate) {
558 std::lock_guard<std::mutex> lock(mMetricsMutex);
559 WriteDataToDiskLocked(key, timestampNs, wallClockNs, CONFIG_UPDATED, NO_TIME_CONSTRAINTS);
560 OnConfigUpdatedLocked(timestampNs, key, config, modularUpdate);
561 }
562
OnConfigUpdated(const int64_t timestampNs,const ConfigKey & key,const StatsdConfig & config,bool modularUpdate)563 void StatsLogProcessor::OnConfigUpdated(const int64_t timestampNs, const ConfigKey& key,
564 const StatsdConfig& config, bool modularUpdate) {
565 OnConfigUpdated(timestampNs, getWallClockNs(), key, config, modularUpdate);
566 }
567
OnConfigUpdatedLocked(const int64_t timestampNs,const ConfigKey & key,const StatsdConfig & config,bool modularUpdate)568 void StatsLogProcessor::OnConfigUpdatedLocked(const int64_t timestampNs, const ConfigKey& key,
569 const StatsdConfig& config, bool modularUpdate) {
570 VLOG("Updated configuration for key %s", key.ToString().c_str());
571 const auto& it = mMetricsManagers.find(key);
572 bool configValid = false;
573 if (isAtLeastU() && it != mMetricsManagers.end()) {
574 if (it->second->hasRestrictedMetricsDelegate() !=
575 config.has_restricted_metrics_delegate_package_name()) {
576 // Not a modular update if has_restricted_metrics_delegate changes
577 modularUpdate = false;
578 }
579 if (!modularUpdate && it->second->hasRestrictedMetricsDelegate()) {
580 StatsdStats::getInstance().noteDbDeletionConfigUpdated(key);
581 // Always delete the old db if restricted metrics config is not a
582 // modular update.
583 dbutils::deleteDb(key);
584 }
585 }
586 // Create new config if this is not a modular update or if this is a new config.
587 if (!modularUpdate || it == mMetricsManagers.end()) {
588 sp<MetricsManager> newMetricsManager =
589 new MetricsManager(key, config, mTimeBaseNs, timestampNs, mUidMap, mPullerManager,
590 mAnomalyAlarmMonitor, mPeriodicAlarmMonitor);
591 configValid = newMetricsManager->isConfigValid();
592 if (configValid) {
593 newMetricsManager->init();
594 newMetricsManager->refreshTtl(timestampNs);
595 // Sdk check for U+ is unnecessary because config with restricted metrics delegate
596 // will be invalid on non U+ devices.
597 if (newMetricsManager->hasRestrictedMetricsDelegate()) {
598 mSendRestrictedMetricsBroadcast(key,
599 newMetricsManager->getRestrictedMetricsDelegate(),
600 newMetricsManager->getAllMetricIds());
601 string err;
602 if (!dbutils::updateDeviceInfoTable(key, err)) {
603 ALOGE("Failed to create device_info table for configKey %s, err: %s",
604 key.ToString().c_str(), err.c_str());
605 StatsdStats::getInstance().noteDeviceInfoTableCreationFailed(key);
606 }
607 } else if (it != mMetricsManagers.end() && it->second->hasRestrictedMetricsDelegate()) {
608 mSendRestrictedMetricsBroadcast(key, it->second->getRestrictedMetricsDelegate(),
609 {});
610 }
611 mMetricsManagers[key] = newMetricsManager;
612 VLOG("StatsdConfig valid");
613 }
614 } else {
615 // Preserve the existing MetricsManager, update necessary components and metadata in place.
616 configValid = it->second->updateConfig(config, mTimeBaseNs, timestampNs,
617 mAnomalyAlarmMonitor, mPeriodicAlarmMonitor);
618 if (configValid && it->second->hasRestrictedMetricsDelegate()) {
619 mSendRestrictedMetricsBroadcast(key, it->second->getRestrictedMetricsDelegate(),
620 it->second->getAllMetricIds());
621 }
622 }
623
624 if (configValid && !config.has_restricted_metrics_delegate_package_name()) {
625 // We do not need to track uid map changes for restricted metrics since the uidmap is not
626 // stored in the sqlite db.
627 mUidMap->OnConfigUpdated(key);
628 } else if (configValid && config.has_restricted_metrics_delegate_package_name()) {
629 mUidMap->OnConfigRemoved(key);
630 }
631 if (!configValid) {
632 // If there is any error in the config, don't use it.
633 // Remove any existing config with the same key.
634 ALOGE("StatsdConfig NOT valid");
635 // Send an empty restricted metrics broadcast if the previous config was restricted.
636 if (isAtLeastU() && it != mMetricsManagers.end() &&
637 it->second->hasRestrictedMetricsDelegate()) {
638 mSendRestrictedMetricsBroadcast(key, it->second->getRestrictedMetricsDelegate(), {});
639 StatsdStats::getInstance().noteDbConfigInvalid(key);
640 dbutils::deleteDb(key);
641 }
642 mMetricsManagers.erase(key);
643 mUidMap->OnConfigRemoved(key);
644 }
645
646 updateLogEventFilterLocked();
647 }
648
GetMetricsSize(const ConfigKey & key) const649 size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const {
650 std::lock_guard<std::mutex> lock(mMetricsMutex);
651 auto it = mMetricsManagers.find(key);
652 if (it == mMetricsManagers.end()) {
653 ALOGW("Config source %s does not exist", key.ToString().c_str());
654 return 0;
655 }
656 return it->second->byteSize();
657 }
658
dumpStates(int out,bool verbose) const659 void StatsLogProcessor::dumpStates(int out, bool verbose) const {
660 std::lock_guard<std::mutex> lock(mMetricsMutex);
661 dprintf(out, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size());
662 for (const auto& metricsManager : mMetricsManagers) {
663 metricsManager.second->dumpStates(out, verbose);
664 }
665 }
666
667 /*
668 * onDumpReport dumps serialized ConfigMetricsReportList into proto.
669 */
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)670 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
671 const int64_t wallClockNs,
672 const bool include_current_partial_bucket,
673 const bool erase_data, const DumpReportReason dumpReportReason,
674 const DumpLatency dumpLatency, ProtoOutputStream* proto) {
675 std::lock_guard<std::mutex> lock(mMetricsMutex);
676
677 auto it = mMetricsManagers.find(key);
678 if (it != mMetricsManagers.end() && it->second->hasRestrictedMetricsDelegate()) {
679 VLOG("Unexpected call to StatsLogProcessor::onDumpReport for restricted metrics.");
680 return;
681 }
682
683 // Start of ConfigKey.
684 uint64_t configKeyToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY);
685 proto->write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid());
686 proto->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId());
687 proto->end(configKeyToken);
688 // End of ConfigKey.
689
690 bool keepFile = false;
691 if (it != mMetricsManagers.end() && it->second->shouldPersistLocalHistory()) {
692 keepFile = true;
693 }
694
695 // Then, check stats-data directory to see there's any file containing
696 // ConfigMetricsReport from previous shutdowns to concatenate to reports.
697 StorageManager::appendConfigMetricsReport(
698 key, proto, erase_data && !keepFile /* should remove file after appending it */,
699 dumpReportReason == ADB_DUMP /*if caller is adb*/);
700
701 if (it != mMetricsManagers.end()) {
702 // This allows another broadcast to be sent within the rate-limit period if we get close to
703 // filling the buffer again soon.
704 mLastBroadcastTimes.erase(key);
705
706 vector<uint8_t> buffer;
707 onConfigMetricsReportLocked(key, dumpTimeStampNs, wallClockNs,
708 include_current_partial_bucket, erase_data, dumpReportReason,
709 dumpLatency, false /* is this data going to be saved on disk */,
710 &buffer);
711 proto->write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS,
712 reinterpret_cast<char*>(buffer.data()), buffer.size());
713 } else {
714 ALOGW("Config source %s does not exist", key.ToString().c_str());
715 }
716
717 if (erase_data) {
718 ++mDumpReportNumbers[key];
719 }
720 proto->write(FIELD_TYPE_INT32 | FIELD_ID_REPORT_NUMBER, mDumpReportNumbers[key]);
721
722 proto->write(FIELD_TYPE_INT32 | FIELD_ID_STATSD_STATS_ID,
723 StatsdStats::getInstance().getStatsdStatsId());
724 if (erase_data) {
725 StatsdStats::getInstance().noteMetricsReportSent(key, proto->size(),
726 mDumpReportNumbers[key]);
727 }
728 }
729
730 /*
731 * onDumpReport dumps serialized ConfigMetricsReportList into outData.
732 */
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)733 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
734 const int64_t wallClockNs,
735 const bool include_current_partial_bucket,
736 const bool erase_data, const DumpReportReason dumpReportReason,
737 const DumpLatency dumpLatency, vector<uint8_t>* outData) {
738 ProtoOutputStream proto;
739 onDumpReport(key, dumpTimeStampNs, wallClockNs, include_current_partial_bucket, erase_data,
740 dumpReportReason, dumpLatency, &proto);
741
742 if (outData != nullptr) {
743 flushProtoToBuffer(proto, outData);
744 VLOG("output data size %zu", outData->size());
745 }
746 }
747
748 /*
749 * For test use only. Excludes wallclockNs.
750 * onDumpReport dumps serialized ConfigMetricsReportList into outData.
751 */
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)752 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
753 const bool include_current_partial_bucket,
754 const bool erase_data, const DumpReportReason dumpReportReason,
755 const DumpLatency dumpLatency, vector<uint8_t>* outData) {
756 onDumpReport(key, dumpTimeStampNs, getWallClockNs(), include_current_partial_bucket, erase_data,
757 dumpReportReason, dumpLatency, outData);
758 }
759
760 /*
761 * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData.
762 */
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)763 void StatsLogProcessor::onConfigMetricsReportLocked(
764 const ConfigKey& key, const int64_t dumpTimeStampNs, const int64_t wallClockNs,
765 const bool include_current_partial_bucket, const bool erase_data,
766 const DumpReportReason dumpReportReason, const DumpLatency dumpLatency,
767 const bool dataSavedOnDisk, vector<uint8_t>* buffer) {
768 // We already checked whether key exists in mMetricsManagers in
769 // WriteDataToDisk.
770 auto it = mMetricsManagers.find(key);
771 if (it == mMetricsManagers.end()) {
772 return;
773 }
774 if (it->second->hasRestrictedMetricsDelegate()) {
775 VLOG("Unexpected call to StatsLogProcessor::onConfigMetricsReportLocked for restricted "
776 "metrics.");
777 // Do not call onDumpReport for restricted metrics.
778 return;
779 }
780
781 // get & forward queue overflow stats to StateManager only when
782 // there is a metric report to be collected, the data loss flags
783 // are not used otherwise
784 processQueueOverflowStatsLocked();
785
786 int64_t lastReportTimeNs = it->second->getLastReportTimeNs();
787 int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs();
788
789 std::set<string> strSet;
790 std::set<int32_t> usedUids;
791
792 int64_t totalSize = it->second->byteSize();
793
794 ProtoOutputStream tempProto;
795 // First, fill in ConfigMetricsReport using current data on memory, which
796 // starts from filling in StatsLogReport's.
797 it->second->onDumpReport(dumpTimeStampNs, wallClockNs, include_current_partial_bucket,
798 erase_data, dumpLatency, &strSet, usedUids, &tempProto);
799
800 // Fill in UidMap if there is at least one metric to report.
801 // This skips the uid map if it's an empty config.
802 if (it->second->getNumMetrics() > 0) {
803 uint64_t uidMapToken = tempProto.start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP);
804 UidMapOptions uidMapOptions = it->second->getUidMapOptions();
805 uidMapOptions.usedUids = std::move(usedUids);
806 mUidMap->appendUidMap(dumpTimeStampNs, key, uidMapOptions,
807 it->second->hashStringInReport() ? &strSet : nullptr, &tempProto);
808 tempProto.end(uidMapToken);
809 }
810
811 // Fill in the timestamps.
812 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS,
813 (long long)lastReportTimeNs);
814 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS,
815 (long long)dumpTimeStampNs);
816 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS,
817 (long long)lastReportWallClockNs);
818 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS,
819 (long long)wallClockNs);
820 // Dump report reason
821 tempProto.write(FIELD_TYPE_INT32 | FIELD_ID_DUMP_REPORT_REASON, dumpReportReason);
822
823 for (const auto& str : strSet) {
824 tempProto.write(FIELD_TYPE_STRING | FIELD_COUNT_REPEATED | FIELD_ID_STRINGS, str);
825 }
826
827 // Data corrupted reason
828 writeDataCorruptedReasons(tempProto, FIELD_ID_DATA_CORRUPTED_REASON,
829 StatsdStats::getInstance().hasEventQueueOverflow(),
830 StatsdStats::getInstance().hasSocketLoss());
831
832 // Estimated memory bytes
833 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_ESTIMATED_DATA_BYTES, totalSize);
834
835 flushProtoToBuffer(tempProto, buffer);
836
837 // save buffer to disk if needed
838 if (erase_data && !dataSavedOnDisk && it->second->shouldPersistLocalHistory()) {
839 VLOG("save history to disk");
840 string file_name = StorageManager::getDataHistoryFileName((long)getWallClockSec(),
841 key.GetUid(), key.GetId());
842 StorageManager::writeFile(file_name.c_str(), buffer->data(), buffer->size());
843 }
844 }
845
resetConfigsLocked(const int64_t timestampNs,const std::vector<ConfigKey> & configs)846 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs,
847 const std::vector<ConfigKey>& configs) {
848 for (const auto& key : configs) {
849 StatsdConfig config;
850 if (StorageManager::readConfigFromDisk(key, &config)) {
851 // Force a full update when resetting a config.
852 OnConfigUpdatedLocked(timestampNs, key, config, /*modularUpdate=*/false);
853 StatsdStats::getInstance().noteConfigReset(key);
854 } else {
855 ALOGE("Failed to read backup config from disk for : %s", key.ToString().c_str());
856 auto it = mMetricsManagers.find(key);
857 if (it != mMetricsManagers.end()) {
858 it->second->refreshTtl(timestampNs);
859 }
860 }
861 }
862 }
863
resetIfConfigTtlExpiredLocked(const int64_t eventTimeNs)864 void StatsLogProcessor::resetIfConfigTtlExpiredLocked(const int64_t eventTimeNs) {
865 std::vector<ConfigKey> configKeysTtlExpired;
866 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
867 if (it->second != nullptr && !it->second->isInTtl(eventTimeNs)) {
868 configKeysTtlExpired.push_back(it->first);
869 }
870 }
871 if (configKeysTtlExpired.size() > 0) {
872 WriteDataToDiskLocked(CONFIG_RESET, NO_TIME_CONSTRAINTS, getElapsedRealtimeNs(),
873 getWallClockNs());
874 resetConfigsLocked(eventTimeNs, configKeysTtlExpired);
875 }
876 }
877
OnConfigRemoved(const ConfigKey & key)878 void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
879 std::lock_guard<std::mutex> lock(mMetricsMutex);
880 auto it = mMetricsManagers.find(key);
881 if (it != mMetricsManagers.end()) {
882 WriteDataToDiskLocked(key, getElapsedRealtimeNs(), getWallClockNs(), CONFIG_REMOVED,
883 NO_TIME_CONSTRAINTS);
884 if (isAtLeastU() && it->second->hasRestrictedMetricsDelegate()) {
885 StatsdStats::getInstance().noteDbDeletionConfigRemoved(key);
886 dbutils::deleteDb(key);
887 mSendRestrictedMetricsBroadcast(key, it->second->getRestrictedMetricsDelegate(), {});
888 }
889 mMetricsManagers.erase(it);
890 mUidMap->OnConfigRemoved(key);
891 }
892 StatsdStats::getInstance().noteConfigRemoved(key);
893
894 mLastBroadcastTimes.erase(key);
895 mLastByteSizeTimes.erase(key);
896 mDumpReportNumbers.erase(key);
897
898 int uid = key.GetUid();
899 bool lastConfigForUid = true;
900 for (const auto& it : mMetricsManagers) {
901 if (it.first.GetUid() == uid) {
902 lastConfigForUid = false;
903 break;
904 }
905 }
906 if (lastConfigForUid) {
907 mLastActivationBroadcastTimes.erase(uid);
908 }
909
910 if (mMetricsManagers.empty()) {
911 mPullerManager->ForceClearPullerCache();
912 }
913
914 updateLogEventFilterLocked();
915 }
916
917 // TODO(b/267501143): Add unit tests when metric producer is ready
enforceDataTtlsIfNecessaryLocked(const int64_t wallClockNs,const int64_t elapsedRealtimeNs)918 void StatsLogProcessor::enforceDataTtlsIfNecessaryLocked(const int64_t wallClockNs,
919 const int64_t elapsedRealtimeNs) {
920 if (!isAtLeastU()) {
921 return;
922 }
923 if (elapsedRealtimeNs - mLastTtlTime < StatsdStats::kMinTtlCheckPeriodNs) {
924 return;
925 }
926 enforceDataTtlsLocked(wallClockNs, elapsedRealtimeNs);
927 }
928
flushRestrictedDataIfNecessaryLocked(const int64_t elapsedRealtimeNs)929 void StatsLogProcessor::flushRestrictedDataIfNecessaryLocked(const int64_t elapsedRealtimeNs) {
930 if (!isAtLeastU()) {
931 return;
932 }
933 if (elapsedRealtimeNs - mLastFlushRestrictedTime < StatsdStats::kMinFlushRestrictedPeriodNs) {
934 return;
935 }
936 flushRestrictedDataLocked(elapsedRealtimeNs);
937 }
938
querySql(const string & sqlQuery,const int32_t minSqlClientVersion,const optional<vector<uint8_t>> & policyConfig,const shared_ptr<IStatsQueryCallback> & callback,const int64_t configId,const string & configPackage,const int32_t callingUid)939 void StatsLogProcessor::querySql(const string& sqlQuery, const int32_t minSqlClientVersion,
940 const optional<vector<uint8_t>>& policyConfig,
941 const shared_ptr<IStatsQueryCallback>& callback,
942 const int64_t configId, const string& configPackage,
943 const int32_t callingUid) {
944 std::lock_guard<std::mutex> lock(mMetricsMutex);
945 string err = "";
946
947 if (!isAtLeastU()) {
948 ALOGW("Restricted metrics query invoked on U- device");
949 StatsdStats::getInstance().noteQueryRestrictedMetricFailed(
950 configId, configPackage, std::nullopt, callingUid,
951 InvalidQueryReason(FLAG_DISABLED));
952 return;
953 }
954
955 const int64_t elapsedRealtimeNs = getElapsedRealtimeNs();
956
957 // TODO(b/268416460): validate policyConfig here
958
959 if (minSqlClientVersion > dbutils::getDbVersion()) {
960 callback->sendFailure(StringPrintf(
961 "Unsupported sqlite version. Installed Version: %d, Requested Version: %d.",
962 dbutils::getDbVersion(), minSqlClientVersion));
963 StatsdStats::getInstance().noteQueryRestrictedMetricFailed(
964 configId, configPackage, std::nullopt, callingUid,
965 InvalidQueryReason(UNSUPPORTED_SQLITE_VERSION));
966 return;
967 }
968
969 set<int32_t> configPackageUids;
970 const auto& uidMapItr = UidMap::sAidToUidMapping.find(configPackage);
971 if (uidMapItr != UidMap::sAidToUidMapping.end()) {
972 configPackageUids.insert(uidMapItr->second);
973 } else {
974 configPackageUids = mUidMap->getAppUid(configPackage);
975 }
976
977 InvalidQueryReason invalidQueryReason;
978 set<ConfigKey> keysToQuery = getRestrictedConfigKeysToQueryLocked(
979 callingUid, configId, configPackageUids, err, invalidQueryReason);
980
981 if (keysToQuery.empty()) {
982 callback->sendFailure(err);
983 StatsdStats::getInstance().noteQueryRestrictedMetricFailed(
984 configId, configPackage, std::nullopt, callingUid,
985 InvalidQueryReason(invalidQueryReason));
986 return;
987 }
988
989 if (keysToQuery.size() > 1) {
990 err = "Ambiguous ConfigKey";
991 callback->sendFailure(err);
992 StatsdStats::getInstance().noteQueryRestrictedMetricFailed(
993 configId, configPackage, std::nullopt, callingUid,
994 InvalidQueryReason(AMBIGUOUS_CONFIG_KEY));
995 return;
996 }
997
998 flushRestrictedDataLocked(elapsedRealtimeNs);
999 enforceDataTtlsLocked(getWallClockNs(), elapsedRealtimeNs);
1000
1001 std::vector<std::vector<std::string>> rows;
1002 std::vector<int32_t> columnTypes;
1003 std::vector<string> columnNames;
1004 if (!dbutils::query(*(keysToQuery.begin()), sqlQuery, rows, columnTypes, columnNames, err)) {
1005 callback->sendFailure(StringPrintf("failed to query db %s:", err.c_str()));
1006 StatsdStats::getInstance().noteQueryRestrictedMetricFailed(
1007 configId, configPackage, keysToQuery.begin()->GetUid(), callingUid,
1008 InvalidQueryReason(QUERY_FAILURE), err.c_str());
1009 return;
1010 }
1011
1012 vector<string> queryData;
1013 queryData.reserve(rows.size() * columnNames.size());
1014 // TODO(b/268415904): avoid this vector transformation.
1015 if (columnNames.size() != columnTypes.size()) {
1016 callback->sendFailure("Inconsistent row sizes");
1017 StatsdStats::getInstance().noteQueryRestrictedMetricFailed(
1018 configId, configPackage, keysToQuery.begin()->GetUid(), callingUid,
1019 InvalidQueryReason(INCONSISTENT_ROW_SIZE));
1020 }
1021 for (size_t i = 0; i < rows.size(); ++i) {
1022 if (rows[i].size() != columnNames.size()) {
1023 callback->sendFailure("Inconsistent row sizes");
1024 StatsdStats::getInstance().noteQueryRestrictedMetricFailed(
1025 configId, configPackage, keysToQuery.begin()->GetUid(), callingUid,
1026 InvalidQueryReason(INCONSISTENT_ROW_SIZE));
1027 return;
1028 }
1029 queryData.insert(std::end(queryData), std::make_move_iterator(std::begin(rows[i])),
1030 std::make_move_iterator(std::end(rows[i])));
1031 }
1032 callback->sendResults(queryData, columnNames, columnTypes, rows.size());
1033 StatsdStats::getInstance().noteQueryRestrictedMetricSucceed(
1034 configId, configPackage, keysToQuery.begin()->GetUid(), callingUid,
1035 /*queryLatencyNs=*/getElapsedRealtimeNs() - elapsedRealtimeNs);
1036 }
1037
getRestrictedConfigKeysToQueryLocked(const int32_t callingUid,const int64_t configId,const set<int32_t> & configPackageUids,string & err,InvalidQueryReason & invalidQueryReason)1038 set<ConfigKey> StatsLogProcessor::getRestrictedConfigKeysToQueryLocked(
1039 const int32_t callingUid, const int64_t configId, const set<int32_t>& configPackageUids,
1040 string& err, InvalidQueryReason& invalidQueryReason) {
1041 set<ConfigKey> matchedConfigKeys;
1042 for (auto uid : configPackageUids) {
1043 ConfigKey configKey(uid, configId);
1044 if (mMetricsManagers.find(configKey) != mMetricsManagers.end()) {
1045 matchedConfigKeys.insert(configKey);
1046 }
1047 }
1048
1049 set<ConfigKey> excludedKeys;
1050 for (auto& configKey : matchedConfigKeys) {
1051 auto it = mMetricsManagers.find(configKey);
1052 if (!it->second->validateRestrictedMetricsDelegate(callingUid)) {
1053 excludedKeys.insert(configKey);
1054 };
1055 }
1056
1057 set<ConfigKey> result;
1058 std::set_difference(matchedConfigKeys.begin(), matchedConfigKeys.end(), excludedKeys.begin(),
1059 excludedKeys.end(), std::inserter(result, result.end()));
1060 if (matchedConfigKeys.empty()) {
1061 err = "No configs found matching the config key";
1062 invalidQueryReason = InvalidQueryReason(CONFIG_KEY_NOT_FOUND);
1063 } else if (result.empty()) {
1064 err = "No matching configs for restricted metrics delegate";
1065 invalidQueryReason = InvalidQueryReason(CONFIG_KEY_WITH_UNMATCHED_DELEGATE);
1066 }
1067
1068 return result;
1069 }
1070
EnforceDataTtls(const int64_t wallClockNs,const int64_t elapsedRealtimeNs)1071 void StatsLogProcessor::EnforceDataTtls(const int64_t wallClockNs,
1072 const int64_t elapsedRealtimeNs) {
1073 if (!isAtLeastU()) {
1074 return;
1075 }
1076 std::lock_guard<std::mutex> lock(mMetricsMutex);
1077 enforceDataTtlsLocked(wallClockNs, elapsedRealtimeNs);
1078 }
1079
enforceDataTtlsLocked(const int64_t wallClockNs,const int64_t elapsedRealtimeNs)1080 void StatsLogProcessor::enforceDataTtlsLocked(const int64_t wallClockNs,
1081 const int64_t elapsedRealtimeNs) {
1082 for (const auto& itr : mMetricsManagers) {
1083 itr.second->enforceRestrictedDataTtls(wallClockNs);
1084 }
1085 mLastTtlTime = elapsedRealtimeNs;
1086 }
1087
enforceDbGuardrailsIfNecessaryLocked(const int64_t wallClockNs,const int64_t elapsedRealtimeNs)1088 void StatsLogProcessor::enforceDbGuardrailsIfNecessaryLocked(const int64_t wallClockNs,
1089 const int64_t elapsedRealtimeNs) {
1090 if (elapsedRealtimeNs - mLastDbGuardrailEnforcementTime <
1091 StatsdStats::kMinDbGuardrailEnforcementPeriodNs) {
1092 return;
1093 }
1094 StorageManager::enforceDbGuardrails(STATS_RESTRICTED_DATA_DIR, wallClockNs / NS_PER_SEC,
1095 StatsdStats::kMaxFileSize);
1096 mLastDbGuardrailEnforcementTime = elapsedRealtimeNs;
1097 }
1098
fillRestrictedMetrics(const int64_t configId,const string & configPackage,const int32_t delegateUid,vector<int64_t> * output)1099 void StatsLogProcessor::fillRestrictedMetrics(const int64_t configId, const string& configPackage,
1100 const int32_t delegateUid, vector<int64_t>* output) {
1101 std::lock_guard<std::mutex> lock(mMetricsMutex);
1102
1103 set<int32_t> configPackageUids;
1104 const auto& uidMapItr = UidMap::sAidToUidMapping.find(configPackage);
1105 if (uidMapItr != UidMap::sAidToUidMapping.end()) {
1106 configPackageUids.insert(uidMapItr->second);
1107 } else {
1108 configPackageUids = mUidMap->getAppUid(configPackage);
1109 }
1110 string err;
1111 InvalidQueryReason invalidQueryReason;
1112 set<ConfigKey> keysToGetMetrics = getRestrictedConfigKeysToQueryLocked(
1113 delegateUid, configId, configPackageUids, err, invalidQueryReason);
1114
1115 for (const ConfigKey& key : keysToGetMetrics) {
1116 vector<int64_t> metricIds = mMetricsManagers[key]->getAllMetricIds();
1117 output->insert(output->end(), metricIds.begin(), metricIds.end());
1118 }
1119 }
1120
flushRestrictedDataLocked(const int64_t elapsedRealtimeNs)1121 void StatsLogProcessor::flushRestrictedDataLocked(const int64_t elapsedRealtimeNs) {
1122 for (const auto& it : mMetricsManagers) {
1123 // no-op if metricsManager is not restricted
1124 it.second->flushRestrictedData();
1125 }
1126
1127 mLastFlushRestrictedTime = elapsedRealtimeNs;
1128 }
1129
flushIfNecessaryLocked(const ConfigKey & key,MetricsManager & metricsManager)1130 void StatsLogProcessor::flushIfNecessaryLocked(const ConfigKey& key,
1131 MetricsManager& metricsManager) {
1132 int64_t elapsedRealtimeNs = getElapsedRealtimeNs();
1133 auto lastCheckTime = mLastByteSizeTimes.find(key);
1134 int64_t minCheckPeriodNs = metricsManager.useV2SoftMemoryCalculation()
1135 ? StatsdStats::kMinByteSizeV2CheckPeriodNs
1136 : StatsdStats::kMinByteSizeCheckPeriodNs;
1137 if (lastCheckTime != mLastByteSizeTimes.end()) {
1138 if (elapsedRealtimeNs - lastCheckTime->second < minCheckPeriodNs) {
1139 return;
1140 }
1141 }
1142
1143 // We suspect that the byteSize() computation is expensive, so we set a rate limit.
1144 size_t totalBytes = metricsManager.byteSize();
1145
1146 mLastByteSizeTimes[key] = elapsedRealtimeNs;
1147 const size_t kBytesPerConfig = metricsManager.hasRestrictedMetricsDelegate()
1148 ? StatsdStats::kBytesPerRestrictedConfigTriggerFlush
1149 : metricsManager.getTriggerGetDataBytes();
1150 bool requestDump = false;
1151 if (totalBytes > metricsManager.getMaxMetricsBytes()) {
1152 // Too late. We need to start clearing data.
1153 metricsManager.dropData(elapsedRealtimeNs);
1154 StatsdStats::getInstance().noteDataDropped(key, totalBytes);
1155 VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
1156 } else if ((totalBytes > kBytesPerConfig) ||
1157 (mOnDiskDataConfigs.find(key) != mOnDiskDataConfigs.end())) {
1158 // Request to dump if:
1159 // 1. in memory data > threshold OR
1160 // 2. config has old data report on disk.
1161 requestDump = true;
1162 }
1163
1164 if (requestDump) {
1165 if (metricsManager.hasRestrictedMetricsDelegate()) {
1166 metricsManager.flushRestrictedData();
1167 // No need to send broadcast for restricted metrics.
1168 return;
1169 }
1170 // Send broadcast so that receivers can pull data.
1171 auto lastBroadcastTime = mLastBroadcastTimes.find(key);
1172 if (lastBroadcastTime != mLastBroadcastTimes.end()) {
1173 if (elapsedRealtimeNs - lastBroadcastTime->second <
1174 StatsdStats::kMinBroadcastPeriodNs) {
1175 VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
1176 return;
1177 }
1178 }
1179 if (mSendBroadcast(key)) {
1180 mOnDiskDataConfigs.erase(key);
1181 VLOG("StatsD triggered data fetch for %s", key.ToString().c_str());
1182 mLastBroadcastTimes[key] = elapsedRealtimeNs;
1183 StatsdStats::getInstance().noteBroadcastSent(key);
1184 }
1185 }
1186 }
1187
WriteDataToDiskLocked(const ConfigKey & key,const int64_t timestampNs,const int64_t wallClockNs,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency)1188 void StatsLogProcessor::WriteDataToDiskLocked(const ConfigKey& key, const int64_t timestampNs,
1189 const int64_t wallClockNs,
1190 const DumpReportReason dumpReportReason,
1191 const DumpLatency dumpLatency) {
1192 if (mMetricsManagers.find(key) == mMetricsManagers.end() ||
1193 !mMetricsManagers.find(key)->second->shouldWriteToDisk()) {
1194 return;
1195 }
1196 if (mMetricsManagers.find(key)->second->hasRestrictedMetricsDelegate()) {
1197 mMetricsManagers.find(key)->second->flushRestrictedData();
1198 return;
1199 }
1200 vector<uint8_t> buffer;
1201 onConfigMetricsReportLocked(key, timestampNs, wallClockNs,
1202 true /* include_current_partial_bucket*/, true /* erase_data */,
1203 dumpReportReason, dumpLatency, true, &buffer);
1204 string file_name =
1205 StorageManager::getDataFileName((long)getWallClockSec(), key.GetUid(), key.GetId());
1206 StorageManager::writeFile(file_name.c_str(), buffer.data(), buffer.size());
1207
1208 // We were able to write the ConfigMetricsReport to disk, so we should trigger collection ASAP.
1209 mOnDiskDataConfigs.insert(key);
1210 }
1211
SaveActiveConfigsToDisk(int64_t currentTimeNs)1212 void StatsLogProcessor::SaveActiveConfigsToDisk(int64_t currentTimeNs) {
1213 std::lock_guard<std::mutex> lock(mMetricsMutex);
1214 const int64_t timeNs = getElapsedRealtimeNs();
1215 // Do not write to disk if we already have in the last few seconds.
1216 if (static_cast<unsigned long long> (timeNs) <
1217 mLastActiveMetricsWriteNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
1218 ALOGI("Statsd skipping writing active metrics to disk. Already wrote data in last %d seconds",
1219 WRITE_DATA_COOL_DOWN_SEC);
1220 return;
1221 }
1222 mLastActiveMetricsWriteNs = timeNs;
1223
1224 ProtoOutputStream proto;
1225 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, DEVICE_SHUTDOWN, &proto);
1226
1227 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
1228 StorageManager::deleteFile(file_name.c_str());
1229 android::base::unique_fd fd(
1230 open(file_name.c_str(), O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR));
1231 if (fd == -1) {
1232 ALOGE("Attempt to write %s but failed", file_name.c_str());
1233 return;
1234 }
1235 proto.flush(fd.get());
1236 }
1237
SaveMetadataToDisk(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)1238 void StatsLogProcessor::SaveMetadataToDisk(int64_t currentWallClockTimeNs,
1239 int64_t systemElapsedTimeNs) {
1240 std::lock_guard<std::mutex> lock(mMetricsMutex);
1241 // Do not write to disk if we already have in the last few seconds.
1242 if (static_cast<unsigned long long> (systemElapsedTimeNs) <
1243 mLastMetadataWriteNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
1244 ALOGI("Statsd skipping writing metadata to disk. Already wrote data in last %d seconds",
1245 WRITE_DATA_COOL_DOWN_SEC);
1246 return;
1247 }
1248 mLastMetadataWriteNs = systemElapsedTimeNs;
1249
1250 metadata::StatsMetadataList metadataList;
1251 WriteMetadataToProtoLocked(
1252 currentWallClockTimeNs, systemElapsedTimeNs, &metadataList);
1253
1254 string file_name = StringPrintf("%s/metadata", STATS_METADATA_DIR);
1255 StorageManager::deleteFile(file_name.c_str());
1256
1257 if (metadataList.stats_metadata_size() == 0) {
1258 // Skip the write if we have nothing to write.
1259 return;
1260 }
1261
1262 std::string data;
1263 metadataList.SerializeToString(&data);
1264 StorageManager::writeFile(file_name.c_str(), data.c_str(), data.size());
1265 }
1266
WriteMetadataToProto(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs,metadata::StatsMetadataList * metadataList)1267 void StatsLogProcessor::WriteMetadataToProto(int64_t currentWallClockTimeNs,
1268 int64_t systemElapsedTimeNs,
1269 metadata::StatsMetadataList* metadataList) {
1270 std::lock_guard<std::mutex> lock(mMetricsMutex);
1271 WriteMetadataToProtoLocked(currentWallClockTimeNs, systemElapsedTimeNs, metadataList);
1272 }
1273
WriteMetadataToProtoLocked(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs,metadata::StatsMetadataList * metadataList)1274 void StatsLogProcessor::WriteMetadataToProtoLocked(int64_t currentWallClockTimeNs,
1275 int64_t systemElapsedTimeNs,
1276 metadata::StatsMetadataList* metadataList) {
1277 for (const auto& pair : mMetricsManagers) {
1278 const sp<MetricsManager>& metricsManager = pair.second;
1279 metadata::StatsMetadata* statsMetadata = metadataList->add_stats_metadata();
1280 bool metadataWritten = metricsManager->writeMetadataToProto(currentWallClockTimeNs,
1281 systemElapsedTimeNs, statsMetadata);
1282 if (!metadataWritten) {
1283 metadataList->mutable_stats_metadata()->RemoveLast();
1284 }
1285 }
1286 }
1287
LoadMetadataFromDisk(int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)1288 void StatsLogProcessor::LoadMetadataFromDisk(int64_t currentWallClockTimeNs,
1289 int64_t systemElapsedTimeNs) {
1290 std::lock_guard<std::mutex> lock(mMetricsMutex);
1291 string file_name = StringPrintf("%s/metadata", STATS_METADATA_DIR);
1292 int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC);
1293 if (-1 == fd) {
1294 VLOG("Attempt to read %s but failed", file_name.c_str());
1295 StorageManager::deleteFile(file_name.c_str());
1296 return;
1297 }
1298 string content;
1299 if (!android::base::ReadFdToString(fd, &content)) {
1300 ALOGE("Attempt to read %s but failed", file_name.c_str());
1301 close(fd);
1302 StorageManager::deleteFile(file_name.c_str());
1303 return;
1304 }
1305
1306 close(fd);
1307
1308 metadata::StatsMetadataList statsMetadataList;
1309 if (!statsMetadataList.ParseFromString(content)) {
1310 ALOGE("Attempt to read %s but failed; failed to metadata", file_name.c_str());
1311 StorageManager::deleteFile(file_name.c_str());
1312 return;
1313 }
1314 SetMetadataStateLocked(statsMetadataList, currentWallClockTimeNs, systemElapsedTimeNs);
1315 StorageManager::deleteFile(file_name.c_str());
1316 }
1317
SetMetadataState(const metadata::StatsMetadataList & statsMetadataList,int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)1318 void StatsLogProcessor::SetMetadataState(const metadata::StatsMetadataList& statsMetadataList,
1319 int64_t currentWallClockTimeNs,
1320 int64_t systemElapsedTimeNs) {
1321 std::lock_guard<std::mutex> lock(mMetricsMutex);
1322 SetMetadataStateLocked(statsMetadataList, currentWallClockTimeNs, systemElapsedTimeNs);
1323 }
1324
SetMetadataStateLocked(const metadata::StatsMetadataList & statsMetadataList,int64_t currentWallClockTimeNs,int64_t systemElapsedTimeNs)1325 void StatsLogProcessor::SetMetadataStateLocked(
1326 const metadata::StatsMetadataList& statsMetadataList,
1327 int64_t currentWallClockTimeNs,
1328 int64_t systemElapsedTimeNs) {
1329 for (const metadata::StatsMetadata& metadata : statsMetadataList.stats_metadata()) {
1330 ConfigKey key(metadata.config_key().uid(), metadata.config_key().config_id());
1331 auto it = mMetricsManagers.find(key);
1332 if (it == mMetricsManagers.end()) {
1333 ALOGE("No config found for configKey %s", key.ToString().c_str());
1334 continue;
1335 }
1336 VLOG("Setting metadata %s", key.ToString().c_str());
1337 it->second->loadMetadata(metadata, currentWallClockTimeNs, systemElapsedTimeNs);
1338 }
1339 VLOG("Successfully loaded %d metadata.", statsMetadataList.stats_metadata_size());
1340 }
1341
WriteActiveConfigsToProtoOutputStream(int64_t currentTimeNs,const DumpReportReason reason,ProtoOutputStream * proto)1342 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStream(
1343 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) {
1344 std::lock_guard<std::mutex> lock(mMetricsMutex);
1345 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, reason, proto);
1346 }
1347
WriteActiveConfigsToProtoOutputStreamLocked(int64_t currentTimeNs,const DumpReportReason reason,ProtoOutputStream * proto)1348 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStreamLocked(
1349 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) {
1350 for (const auto& pair : mMetricsManagers) {
1351 const sp<MetricsManager>& metricsManager = pair.second;
1352 uint64_t configToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED |
1353 FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG);
1354 metricsManager->writeActiveConfigToProtoOutputStream(currentTimeNs, reason, proto);
1355 proto->end(configToken);
1356 }
1357 }
LoadActiveConfigsFromDisk()1358 void StatsLogProcessor::LoadActiveConfigsFromDisk() {
1359 std::lock_guard<std::mutex> lock(mMetricsMutex);
1360 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
1361 int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC);
1362 if (-1 == fd) {
1363 VLOG("Attempt to read %s but failed", file_name.c_str());
1364 StorageManager::deleteFile(file_name.c_str());
1365 return;
1366 }
1367 string content;
1368 if (!android::base::ReadFdToString(fd, &content)) {
1369 ALOGE("Attempt to read %s but failed", file_name.c_str());
1370 close(fd);
1371 StorageManager::deleteFile(file_name.c_str());
1372 return;
1373 }
1374
1375 close(fd);
1376
1377 ActiveConfigList activeConfigList;
1378 if (!activeConfigList.ParseFromString(content)) {
1379 ALOGE("Attempt to read %s but failed; failed to load active configs", file_name.c_str());
1380 StorageManager::deleteFile(file_name.c_str());
1381 return;
1382 }
1383 // Passing in mTimeBaseNs only works as long as we only load from disk is when statsd starts.
1384 SetConfigsActiveStateLocked(activeConfigList, mTimeBaseNs);
1385 StorageManager::deleteFile(file_name.c_str());
1386 }
1387
SetConfigsActiveState(const ActiveConfigList & activeConfigList,int64_t currentTimeNs)1388 void StatsLogProcessor::SetConfigsActiveState(const ActiveConfigList& activeConfigList,
1389 int64_t currentTimeNs) {
1390 std::lock_guard<std::mutex> lock(mMetricsMutex);
1391 SetConfigsActiveStateLocked(activeConfigList, currentTimeNs);
1392 }
1393
SetConfigsActiveStateLocked(const ActiveConfigList & activeConfigList,int64_t currentTimeNs)1394 void StatsLogProcessor::SetConfigsActiveStateLocked(const ActiveConfigList& activeConfigList,
1395 int64_t currentTimeNs) {
1396 for (int i = 0; i < activeConfigList.config_size(); i++) {
1397 const auto& config = activeConfigList.config(i);
1398 ConfigKey key(config.uid(), config.id());
1399 auto it = mMetricsManagers.find(key);
1400 if (it == mMetricsManagers.end()) {
1401 ALOGE("No config found for config %s", key.ToString().c_str());
1402 continue;
1403 }
1404 VLOG("Setting active config %s", key.ToString().c_str());
1405 it->second->loadActiveConfig(config, currentTimeNs);
1406 }
1407 VLOG("Successfully loaded %d active configs.", activeConfigList.config_size());
1408 }
1409
WriteDataToDiskLocked(const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,const int64_t elapsedRealtimeNs,const int64_t wallClockNs)1410 void StatsLogProcessor::WriteDataToDiskLocked(const DumpReportReason dumpReportReason,
1411 const DumpLatency dumpLatency,
1412 const int64_t elapsedRealtimeNs,
1413 const int64_t wallClockNs) {
1414 // Do not write to disk if we already have in the last few seconds.
1415 // This is to avoid overwriting files that would have the same name if we
1416 // write twice in the same second.
1417 if (static_cast<unsigned long long>(elapsedRealtimeNs) <
1418 mLastWriteTimeNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
1419 ALOGI("Statsd skipping writing data to disk. Already wrote data in last %d seconds",
1420 WRITE_DATA_COOL_DOWN_SEC);
1421 return;
1422 }
1423 mLastWriteTimeNs = elapsedRealtimeNs;
1424 for (auto& pair : mMetricsManagers) {
1425 WriteDataToDiskLocked(pair.first, elapsedRealtimeNs, wallClockNs, dumpReportReason,
1426 dumpLatency);
1427 }
1428 }
1429
WriteDataToDisk(const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,const int64_t elapsedRealtimeNs,const int64_t wallClockNs)1430 void StatsLogProcessor::WriteDataToDisk(const DumpReportReason dumpReportReason,
1431 const DumpLatency dumpLatency,
1432 const int64_t elapsedRealtimeNs,
1433 const int64_t wallClockNs) {
1434 std::lock_guard<std::mutex> lock(mMetricsMutex);
1435 WriteDataToDiskLocked(dumpReportReason, dumpLatency, elapsedRealtimeNs, wallClockNs);
1436 }
1437
informPullAlarmFired(const int64_t timestampNs)1438 void StatsLogProcessor::informPullAlarmFired(const int64_t timestampNs) {
1439 std::lock_guard<std::mutex> lock(mMetricsMutex);
1440 mPullerManager->OnAlarmFired(timestampNs);
1441 }
1442
getLastReportTimeNs(const ConfigKey & key)1443 int64_t StatsLogProcessor::getLastReportTimeNs(const ConfigKey& key) {
1444 auto it = mMetricsManagers.find(key);
1445 if (it == mMetricsManagers.end()) {
1446 return 0;
1447 } else {
1448 return it->second->getLastReportTimeNs();
1449 }
1450 }
1451
notifyAppUpgrade(const int64_t eventTimeNs,const string & apk,const int uid,const int64_t version)1452 void StatsLogProcessor::notifyAppUpgrade(const int64_t eventTimeNs, const string& apk,
1453 const int uid, const int64_t version) {
1454 std::lock_guard<std::mutex> lock(mMetricsMutex);
1455 VLOG("Received app upgrade");
1456 StateManager::getInstance().notifyAppChanged(apk, mUidMap);
1457 for (const auto& it : mMetricsManagers) {
1458 it.second->notifyAppUpgrade(eventTimeNs, apk, uid, version);
1459 }
1460 }
1461
notifyAppRemoved(const int64_t eventTimeNs,const string & apk,const int uid)1462 void StatsLogProcessor::notifyAppRemoved(const int64_t eventTimeNs, const string& apk,
1463 const int uid) {
1464 std::lock_guard<std::mutex> lock(mMetricsMutex);
1465 VLOG("Received app removed");
1466 StateManager::getInstance().notifyAppChanged(apk, mUidMap);
1467 for (const auto& it : mMetricsManagers) {
1468 it.second->notifyAppRemoved(eventTimeNs, apk, uid);
1469 }
1470 }
1471
onUidMapReceived(const int64_t eventTimeNs)1472 void StatsLogProcessor::onUidMapReceived(const int64_t eventTimeNs) {
1473 std::lock_guard<std::mutex> lock(mMetricsMutex);
1474 VLOG("Received uid map");
1475 StateManager::getInstance().updateLogSources(mUidMap);
1476 for (const auto& it : mMetricsManagers) {
1477 it.second->onUidMapReceived(eventTimeNs);
1478 }
1479 }
1480
onStatsdInitCompleted(const int64_t elapsedTimeNs)1481 void StatsLogProcessor::onStatsdInitCompleted(const int64_t elapsedTimeNs) {
1482 ATRACE_CALL();
1483 std::lock_guard<std::mutex> lock(mMetricsMutex);
1484 VLOG("Received boot completed signal");
1485 for (const auto& it : mMetricsManagers) {
1486 it.second->onStatsdInitCompleted(elapsedTimeNs);
1487 }
1488 }
1489
noteOnDiskData(const ConfigKey & key)1490 void StatsLogProcessor::noteOnDiskData(const ConfigKey& key) {
1491 std::lock_guard<std::mutex> lock(mMetricsMutex);
1492 mOnDiskDataConfigs.insert(key);
1493 }
1494
setAnomalyAlarm(const int64_t elapsedTimeMillis)1495 void StatsLogProcessor::setAnomalyAlarm(const int64_t elapsedTimeMillis) {
1496 std::lock_guard<std::mutex> lock(mAnomalyAlarmMutex);
1497 mNextAnomalyAlarmTime = elapsedTimeMillis;
1498 }
1499
cancelAnomalyAlarm()1500 void StatsLogProcessor::cancelAnomalyAlarm() {
1501 std::lock_guard<std::mutex> lock(mAnomalyAlarmMutex);
1502 mNextAnomalyAlarmTime = 0;
1503 }
1504
informAnomalyAlarmFiredLocked(const int64_t elapsedTimeMillis)1505 void StatsLogProcessor::informAnomalyAlarmFiredLocked(const int64_t elapsedTimeMillis) {
1506 VLOG("StatsService::informAlarmForSubscriberTriggeringFired was called");
1507 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet =
1508 mAnomalyAlarmMonitor->popSoonerThan(static_cast<uint32_t>(elapsedTimeMillis / 1000));
1509 if (alarmSet.size() > 0) {
1510 VLOG("Found periodic alarm fired.");
1511 processFiredAnomalyAlarmsLocked(MillisToNano(elapsedTimeMillis), alarmSet);
1512 } else {
1513 ALOGW("Cannot find an periodic alarm that fired. Perhaps it was recently cancelled.");
1514 }
1515 }
1516
getDefaultAtomIdSet()1517 LogEventFilter::AtomIdSet StatsLogProcessor::getDefaultAtomIdSet() {
1518 // populate hard-coded list of useful atoms
1519 // we add also atoms which could be pushed by statsd itself to simplify the logic
1520 // to handle metric configs update: APP_BREADCRUMB_REPORTED & ANOMALY_DETECTED
1521 LogEventFilter::AtomIdSet allAtomIds{
1522 util::BINARY_PUSH_STATE_CHANGED, util::ISOLATED_UID_CHANGED,
1523 util::APP_BREADCRUMB_REPORTED, util::WATCHDOG_ROLLBACK_OCCURRED,
1524 util::ANOMALY_DETECTED, util::STATS_SOCKET_LOSS_REPORTED};
1525 return allAtomIds;
1526 }
1527
updateLogEventFilterLocked() const1528 void StatsLogProcessor::updateLogEventFilterLocked() const {
1529 VLOG("StatsLogProcessor: Updating allAtomIds at %lld", (long long)getElapsedRealtimeNs());
1530 LogEventFilter::AtomIdSet allAtomIds = getDefaultAtomIdSet();
1531 for (const auto& metricsManager : mMetricsManagers) {
1532 metricsManager.second->addAllAtomIds(allAtomIds);
1533 }
1534 StateManager::getInstance().addAllAtomIds(allAtomIds);
1535 VLOG("StatsLogProcessor: Updating allAtomIds done. Total atoms %d", (int)allAtomIds.size());
1536 #ifdef STATSD_DEBUG
1537 for (auto atomId : allAtomIds) {
1538 VLOG("Atom in use %d", atomId);
1539 }
1540 #endif // STATSD_DEBUG
1541 mLogEventFilter->setAtomIds(std::move(allAtomIds), this);
1542 }
1543
validateAppBreadcrumbEvent(const LogEvent & event) const1544 bool StatsLogProcessor::validateAppBreadcrumbEvent(const LogEvent& event) const {
1545 if (event.GetTagId() == util::APP_BREADCRUMB_REPORTED) {
1546 // Check that app breadcrumb reported fields are valid.
1547 status_t err = NO_ERROR;
1548
1549 // Uid is 3rd from last field and must match the caller's uid,
1550 // unless that caller is statsd itself (statsd is allowed to spoof uids).
1551 const long appHookUid = event.GetLong(event.size() - 2, &err);
1552 if (err != NO_ERROR) {
1553 VLOG("APP_BREADCRUMB_REPORTED had error when parsing the uid");
1554 return false;
1555 }
1556
1557 // Because the uid within the LogEvent may have been mapped from
1558 // isolated to host, map the loggerUid similarly before comparing.
1559 const int32_t loggerUid = mUidMap->getHostUidOrSelf(event.GetUid());
1560 if (loggerUid != appHookUid && loggerUid != AID_STATSD) {
1561 VLOG("APP_BREADCRUMB_REPORTED has invalid uid: claimed %ld but caller is %d",
1562 appHookUid, loggerUid);
1563 return false;
1564 }
1565
1566 // The state must be from 0,3. This part of code must be manually updated.
1567 const long appHookState = event.GetLong(event.size(), &err);
1568 if (err != NO_ERROR) {
1569 VLOG("APP_BREADCRUMB_REPORTED had error when parsing the state field");
1570 return false;
1571 } else if (appHookState < 0 || appHookState > 3) {
1572 VLOG("APP_BREADCRUMB_REPORTED does not have valid state %ld", appHookState);
1573 return false;
1574 }
1575 }
1576
1577 return true;
1578 }
1579
processQueueOverflowStatsLocked()1580 void StatsLogProcessor::processQueueOverflowStatsLocked() {
1581 auto queueOverflowStats = StatsdStats::getInstance().getQueueOverflowAtomsStats();
1582
1583 for (const auto [atomId, count] : queueOverflowStats) {
1584 // are there new atoms dropped due to queue overflow since previous request
1585 auto droppedAtomStatsIt = mQueueOverflowAtomsStats.find(atomId);
1586 if (droppedAtomStatsIt != mQueueOverflowAtomsStats.end() &&
1587 droppedAtomStatsIt->second == count) {
1588 // no new dropped atoms detected for the atomId
1589 continue;
1590 }
1591
1592 StateManager::getInstance().onLogEventLost(atomId, DATA_CORRUPTED_EVENT_QUEUE_OVERFLOW);
1593 }
1594 mQueueOverflowAtomsStats = std::move(queueOverflowStats);
1595 }
1596
1597 } // namespace statsd
1598 } // namespace os
1599 } // namespace android
1600