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