blob: 69b9fc7ad9a09f9a792290dac7d1ac3deb47e963 [file] [log] [blame]
Yao Chenab273e22017-09-06 12:53:50 -07001/*
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
Chenjie Yuc7939cb2019-02-04 17:25:45 -080017#define DEBUG false // STOPSHIP if true
Joe Onorato9fc9edf2017-10-15 20:08:52 -070018#include "Log.h"
tsaichristined21aacf2019-10-07 14:47:38 -070019
20#include "StatsLogProcessor.h"
Yao Chenab273e22017-09-06 12:53:50 -070021
yro947fbce2017-11-15 22:50:23 -080022#include <android-base/file.h>
Jonathan Nguyena0e6de12020-01-28 18:33:55 -080023#include <cutils/multiuser.h>
Chenjie Yuc7939cb2019-02-04 17:25:45 -080024#include <frameworks/base/cmds/statsd/src/active_config_list.pb.h>
Jonathan Nguyena0e6de12020-01-28 18:33:55 -080025#include <frameworks/base/cmds/statsd/src/experiment_ids.pb.h>
tsaichristined21aacf2019-10-07 14:47:38 -070026
yro947fbce2017-11-15 22:50:23 -080027#include "android-base/stringprintf.h"
Muhammad Qureshic8e22662019-11-20 17:18:03 -080028#include "atoms_info.h"
Chenjie Yuc7939cb2019-02-04 17:25:45 -080029#include "external/StatsPullerManager.h"
Yao Chenb3561512017-11-21 18:07:17 -080030#include "guardrail/StatsdStats.h"
Jonathan Nguyena0e6de12020-01-28 18:33:55 -080031#include "logd/LogEvent.h"
Joe Onorato9fc9edf2017-10-15 20:08:52 -070032#include "metrics/CountMetricProducer.h"
Jonathan Nguyena0e6de12020-01-28 18:33:55 -080033#include "StatsService.h"
tsaichristined21aacf2019-10-07 14:47:38 -070034#include "state/StateManager.h"
Chenjie Yuc7939cb2019-02-04 17:25:45 -080035#include "stats_log_util.h"
Joe Onorato9fc9edf2017-10-15 20:08:52 -070036#include "stats_util.h"
Jeffrey Huang74fc4352020-03-06 15:18:33 -080037#include "statslog_statsd.h"
yro947fbce2017-11-15 22:50:23 -080038#include "storage/StorageManager.h"
Joe Onorato9fc9edf2017-10-15 20:08:52 -070039
Yao Chenab273e22017-09-06 12:53:50 -070040using namespace android;
yro947fbce2017-11-15 22:50:23 -080041using android::base::StringPrintf;
yrob0378b02017-11-09 20:36:25 -080042using android::util::FIELD_COUNT_REPEATED;
yro17adac92017-11-08 23:16:29 -080043using android::util::FIELD_TYPE_BOOL;
44using android::util::FIELD_TYPE_FLOAT;
45using android::util::FIELD_TYPE_INT32;
46using android::util::FIELD_TYPE_INT64;
47using android::util::FIELD_TYPE_MESSAGE;
48using android::util::FIELD_TYPE_STRING;
49using android::util::ProtoOutputStream;
Yao Chen44cf27c2017-09-14 22:32:50 -070050using std::vector;
Bookatz906a35c2017-09-20 15:26:44 -070051
52namespace android {
53namespace os {
54namespace statsd {
Yao Chenab273e22017-09-06 12:53:50 -070055
yro947fbce2017-11-15 22:50:23 -080056// for ConfigMetricsReportList
yro17adac92017-11-08 23:16:29 -080057const int FIELD_ID_CONFIG_KEY = 1;
yro947fbce2017-11-15 22:50:23 -080058const int FIELD_ID_REPORTS = 2;
yro17adac92017-11-08 23:16:29 -080059// for ConfigKey
60const int FIELD_ID_UID = 1;
Yangster-mac94e197c2018-01-02 16:03:03 -080061const int FIELD_ID_ID = 2;
yro947fbce2017-11-15 22:50:23 -080062// for ConfigMetricsReport
Yao Chen4c959cb2018-02-13 13:27:48 -080063// const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp
yro947fbce2017-11-15 22:50:23 -080064const int FIELD_ID_UID_MAP = 2;
Yangster-mac330af582018-02-08 15:24:38 -080065const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3;
66const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4;
Yangster-mac3fa5d7f2018-03-10 21:50:27 -080067const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5;
68const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6;
Chenjie Yue36018b2018-04-16 15:18:30 -070069const int FIELD_ID_DUMP_REPORT_REASON = 8;
Yangster-mac9def8e32018-04-17 13:55:51 -070070const int FIELD_ID_STRINGS = 9;
Yangster-mac3fa5d7f2018-03-10 21:50:27 -080071
Muhammad Qureshi844694b2019-04-05 10:10:40 -070072// for ActiveConfigList
73const int FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG = 1;
Chenjie Yuc7939cb2019-02-04 17:25:45 -080074
Jonathan Nguyena0e6de12020-01-28 18:33:55 -080075// for permissions checks
76constexpr const char* kPermissionDump = "android.permission.DUMP";
77constexpr const char* kPermissionUsage = "android.permission.PACKAGE_USAGE_STATS";
78
Yangster-macb142cc82018-03-30 15:22:08 -070079#define NS_PER_HOUR 3600 * NS_PER_SEC
yro947fbce2017-11-15 22:50:23 -080080
Chenjie Yuc7939cb2019-02-04 17:25:45 -080081#define STATS_ACTIVE_METRIC_DIR "/data/misc/stats-active-metric"
yro17adac92017-11-08 23:16:29 -080082
Tej Singh42f9e062018-11-09 10:01:00 -080083// Cool down period for writing data to disk to avoid overwriting files.
84#define WRITE_DATA_COOL_DOWN_SEC 5
85
yro31eb67b2017-10-24 13:33:21 -070086StatsLogProcessor::StatsLogProcessor(const sp<UidMap>& uidMap,
Chenjie Yue2219202018-06-08 10:07:51 -070087 const sp<StatsPullerManager>& pullerManager,
Yangster-mac932ecec2018-02-01 10:23:52 -080088 const sp<AlarmMonitor>& anomalyAlarmMonitor,
89 const sp<AlarmMonitor>& periodicAlarmMonitor,
Yangster-mac15f6bbc2018-04-08 11:52:26 -070090 const int64_t timeBaseNs,
Tej Singh6ede28b2019-01-29 17:06:54 -080091 const std::function<bool(const ConfigKey&)>& sendBroadcast,
92 const std::function<bool(
93 const int&, const vector<int64_t>&)>& activateBroadcast)
Chenjie Yu85ed8382017-12-14 16:48:54 -080094 : mUidMap(uidMap),
Chenjie Yue2219202018-06-08 10:07:51 -070095 mPullerManager(pullerManager),
Yangster-mac932ecec2018-02-01 10:23:52 -080096 mAnomalyAlarmMonitor(anomalyAlarmMonitor),
97 mPeriodicAlarmMonitor(periodicAlarmMonitor),
Chenjie Yu85ed8382017-12-14 16:48:54 -080098 mSendBroadcast(sendBroadcast),
Tej Singh6ede28b2019-01-29 17:06:54 -080099 mSendActivationBroadcast(activateBroadcast),
Yangster-mac15f6bbc2018-04-08 11:52:26 -0700100 mTimeBaseNs(timeBaseNs),
Yao Chen163d2602018-04-10 10:39:53 -0700101 mLargestTimestampSeen(0),
102 mLastTimestampSeen(0) {
Chenjie Yue2219202018-06-08 10:07:51 -0700103 mPullerManager->ForceClearPullerCache();
Yao Chenab273e22017-09-06 12:53:50 -0700104}
105
Yao Chenef99c4f2017-09-22 16:26:54 -0700106StatsLogProcessor::~StatsLogProcessor() {
Yao Chenab273e22017-09-06 12:53:50 -0700107}
108
Yao Chen9a43b4f2019-04-10 10:43:20 -0700109static void flushProtoToBuffer(ProtoOutputStream& proto, vector<uint8_t>* outData) {
110 outData->clear();
111 outData->resize(proto.size());
112 size_t pos = 0;
113 sp<android::util::ProtoReader> reader = proto.data();
114 while (reader->readBuffer() != NULL) {
115 size_t toRead = reader->currentToRead();
116 std::memcpy(&((*outData)[pos]), reader->readBuffer(), toRead);
117 pos += toRead;
118 reader->move(toRead);
119 }
120}
121
Yangster-mace2cd6d52017-11-09 20:38:30 -0800122void StatsLogProcessor::onAnomalyAlarmFired(
Yangster-macb142cc82018-03-30 15:22:08 -0700123 const int64_t& timestampNs,
Yangster-mac932ecec2018-02-01 10:23:52 -0800124 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
Yangster-macb0d06282018-01-05 15:44:07 -0800125 std::lock_guard<std::mutex> lock(mMetricsMutex);
Bookatzcc5adef22017-11-21 14:36:23 -0800126 for (const auto& itr : mMetricsManagers) {
Yangster-mac932ecec2018-02-01 10:23:52 -0800127 itr.second->onAnomalyAlarmFired(timestampNs, alarmSet);
128 }
129}
130void StatsLogProcessor::onPeriodicAlarmFired(
Yangster-macb142cc82018-03-30 15:22:08 -0700131 const int64_t& timestampNs,
Yangster-mac932ecec2018-02-01 10:23:52 -0800132 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
133
134 std::lock_guard<std::mutex> lock(mMetricsMutex);
135 for (const auto& itr : mMetricsManagers) {
136 itr.second->onPeriodicAlarmFired(timestampNs, alarmSet);
Yangster-mace2cd6d52017-11-09 20:38:30 -0800137 }
138}
139
Yao Chen8a8d16c2018-02-08 14:50:40 -0800140void updateUid(Value* value, int hostUid) {
141 int uid = value->int_value;
142 if (uid != hostUid) {
143 value->setInt(hostUid);
144 }
145}
146
Yangster-macd40053e2018-01-09 16:29:22 -0800147void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const {
Yao Chenc40a19d2018-03-15 16:48:25 -0700148 if (android::util::AtomsInfo::kAtomsWithAttributionChain.find(event->GetTagId()) !=
149 android::util::AtomsInfo::kAtomsWithAttributionChain.end()) {
Yao Chen8a8d16c2018-02-08 14:50:40 -0800150 for (auto& value : *(event->getMutableValues())) {
151 if (value.mField.getPosAtDepth(0) > kAttributionField) {
152 break;
153 }
154 if (isAttributionUidField(value)) {
155 const int hostUid = mUidMap->getHostUidOrSelf(value.mValue.int_value);
156 updateUid(&value.mValue, hostUid);
157 }
Yangster-macd40053e2018-01-09 16:29:22 -0800158 }
Yao Chenc40a19d2018-03-15 16:48:25 -0700159 } else {
160 auto it = android::util::AtomsInfo::kAtomsWithUidField.find(event->GetTagId());
161 if (it != android::util::AtomsInfo::kAtomsWithUidField.end()) {
162 int uidField = it->second; // uidField is the field number in proto,
163 // starting from 1
164 if (uidField > 0 && (int)event->getValues().size() >= uidField &&
165 (event->getValues())[uidField - 1].mValue.getType() == INT) {
166 Value& value = (*event->getMutableValues())[uidField - 1].mValue;
167 const int hostUid = mUidMap->getHostUidOrSelf(value.int_value);
168 updateUid(&value, hostUid);
169 } else {
170 ALOGE("Malformed log, uid not found. %s", event->ToString().c_str());
171 }
172 }
Yao Chen312e8982017-12-05 15:29:03 -0800173 }
Yangster-macd40053e2018-01-09 16:29:22 -0800174}
175
176void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
177 status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR;
178 bool is_create = event.GetBool(3, &err);
179 auto parent_uid = int(event.GetLong(1, &err2));
180 auto isolated_uid = int(event.GetLong(2, &err3));
181 if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) {
182 if (is_create) {
183 mUidMap->assignIsolatedUid(isolated_uid, parent_uid);
184 } else {
Bookatz3c648862018-05-25 13:32:43 -0700185 mUidMap->removeIsolatedUid(isolated_uid);
Yangster-macd40053e2018-01-09 16:29:22 -0800186 }
187 } else {
188 ALOGE("Failed to parse uid in the isolated uid change event.");
189 }
190}
191
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800192void StatsLogProcessor::onBinaryPushStateChangedEventLocked(LogEvent* event) {
193 pid_t pid = event->GetPid();
194 uid_t uid = event->GetUid();
195 if (!checkPermissionForIds(kPermissionDump, pid, uid) ||
196 !checkPermissionForIds(kPermissionUsage, pid, uid)) {
197 return;
198 }
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800199 // The Get* functions don't modify the status on success, they only write in
200 // failure statuses, so we can use one status variable for all calls then
201 // check if it is no longer NO_ERROR.
202 status_t err = NO_ERROR;
203 InstallTrainInfo trainInfo;
204 trainInfo.trainName = string(event->GetString(1 /*train name field id*/, &err));
205 trainInfo.trainVersionCode = event->GetLong(2 /*train version field id*/, &err);
206 trainInfo.requiresStaging = event->GetBool(3 /*requires staging field id*/, &err);
207 trainInfo.rollbackEnabled = event->GetBool(4 /*rollback enabled field id*/, &err);
208 trainInfo.requiresLowLatencyMonitor =
209 event->GetBool(5 /*requires low latency monitor field id*/, &err);
210 trainInfo.status = int32_t(event->GetLong(6 /*state field id*/, &err));
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800211 std::vector<uint8_t> trainExperimentIdBytes =
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800212 event->GetStorage(7 /*experiment ids field id*/, &err);
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800213 bool is_rollback = event->GetBool(10 /*is rollback field id*/, &err);
214
215 if (err != NO_ERROR) {
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800216 ALOGE("Failed to parse fields in binary push state changed log event");
217 return;
218 }
219 ExperimentIds trainExperimentIds;
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800220 if (!trainExperimentIds.ParseFromArray(trainExperimentIdBytes.data(),
221 trainExperimentIdBytes.size())) {
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800222 ALOGE("Failed to parse experimentids in binary push state changed.");
223 return;
224 }
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800225 trainInfo.experimentIds = {trainExperimentIds.experiment_id().begin(),
226 trainExperimentIds.experiment_id().end()};
227
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800228 // Update the train info on disk and get any data the logevent is missing.
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800229 getAndUpdateTrainInfoOnDisk(is_rollback, &trainInfo);
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800230
231 std::vector<uint8_t> trainExperimentIdProto;
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800232 writeExperimentIdsToProto(trainInfo.experimentIds, &trainExperimentIdProto);
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800233 int32_t userId = multiuser_get_user_id(uid);
234
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800235 event->updateValue(2 /*train version field id*/, trainInfo.trainVersionCode, LONG);
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800236 event->updateValue(7 /*experiment ids field id*/, trainExperimentIdProto, STORAGE);
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800237 event->updateValue(8 /*user id field id*/, userId, INT);
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800238
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800239 // If this event is a rollback event, then the following bits in the event
240 // are invalid and we will need to update them with the values we pulled
241 // from disk.
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800242 if (is_rollback) {
243 int bit = trainInfo.requiresStaging ? 1 : 0;
244 event->updateValue(3 /*requires staging field id*/, bit, INT);
245 bit = trainInfo.rollbackEnabled ? 1 : 0;
246 event->updateValue(4 /*rollback enabled field id*/, bit, INT);
247 bit = trainInfo.requiresLowLatencyMonitor ? 1 : 0;
248 event->updateValue(5 /*requires low latency monitor field id*/, bit, INT);
249 }
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800250}
251
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800252void StatsLogProcessor::getAndUpdateTrainInfoOnDisk(bool is_rollback,
253 InstallTrainInfo* trainInfo) {
254 // If the train name is empty, we don't know which train to attribute the
255 // event to, so return early.
256 if (trainInfo->trainName.empty()) {
257 return;
258 }
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800259 bool readTrainInfoSuccess = false;
260 InstallTrainInfo trainInfoOnDisk;
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800261 readTrainInfoSuccess = StorageManager::readTrainInfo(trainInfo->trainName, trainInfoOnDisk);
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800262
263 bool resetExperimentIds = false;
264 if (readTrainInfoSuccess) {
265 // Keep the old train version if we received an empty version.
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800266 if (trainInfo->trainVersionCode == -1) {
267 trainInfo->trainVersionCode = trainInfoOnDisk.trainVersionCode;
268 } else if (trainInfo->trainVersionCode != trainInfoOnDisk.trainVersionCode) {
269 // Reset experiment ids if we receive a new non-empty train version.
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800270 resetExperimentIds = true;
271 }
272
273 // Reset if we received a different experiment id.
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800274 if (!trainInfo->experimentIds.empty() &&
275 (trainInfoOnDisk.experimentIds.empty() ||
276 trainInfo->experimentIds.at(0) != trainInfoOnDisk.experimentIds[0])) {
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800277 resetExperimentIds = true;
278 }
279 }
280
281 // Find the right experiment IDs
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800282 if ((!resetExperimentIds || is_rollback) && readTrainInfoSuccess) {
283 trainInfo->experimentIds = trainInfoOnDisk.experimentIds;
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800284 }
285
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800286 if (!trainInfo->experimentIds.empty()) {
287 int64_t firstId = trainInfo->experimentIds.at(0);
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800288 auto& ids = trainInfo->experimentIds;
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800289 switch (trainInfo->status) {
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800290 case android::os::statsd::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALL_SUCCESS:
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800291 if (find(ids.begin(), ids.end(), firstId + 1) == ids.end()) {
292 ids.push_back(firstId + 1);
293 }
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800294 break;
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800295 case android::os::statsd::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_INITIATED:
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800296 if (find(ids.begin(), ids.end(), firstId + 2) == ids.end()) {
297 ids.push_back(firstId + 2);
298 }
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800299 break;
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800300 case android::os::statsd::util::BINARY_PUSH_STATE_CHANGED__STATE__INSTALLER_ROLLBACK_SUCCESS:
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800301 if (find(ids.begin(), ids.end(), firstId + 3) == ids.end()) {
302 ids.push_back(firstId + 3);
303 }
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800304 break;
305 }
306 }
307
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800308 // If this event is a rollback event, the following fields are invalid and
309 // need to be replaced by the fields stored to disk.
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800310 if (is_rollback) {
311 trainInfo->requiresStaging = trainInfoOnDisk.requiresStaging;
312 trainInfo->rollbackEnabled = trainInfoOnDisk.rollbackEnabled;
313 trainInfo->requiresLowLatencyMonitor = trainInfoOnDisk.requiresLowLatencyMonitor;
314 }
315
316 StorageManager::writeTrainInfo(*trainInfo);
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800317}
318
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800319void StatsLogProcessor::onWatchdogRollbackOccurredLocked(LogEvent* event) {
320 pid_t pid = event->GetPid();
321 uid_t uid = event->GetUid();
322 if (!checkPermissionForIds(kPermissionDump, pid, uid) ||
323 !checkPermissionForIds(kPermissionUsage, pid, uid)) {
324 return;
325 }
326 // The Get* functions don't modify the status on success, they only write in
327 // failure statuses, so we can use one status variable for all calls then
328 // check if it is no longer NO_ERROR.
329 status_t err = NO_ERROR;
330 int32_t rollbackType = int32_t(event->GetInt(1 /*rollback type field id*/, &err));
331 string packageName = string(event->GetString(2 /*package name field id*/, &err));
332
333 if (err != NO_ERROR) {
334 ALOGE("Failed to parse fields in watchdog rollback occurred log event");
335 return;
336 }
337
338 vector<int64_t> experimentIds =
339 processWatchdogRollbackOccurred(rollbackType, packageName);
340 vector<uint8_t> experimentIdProto;
341 writeExperimentIdsToProto(experimentIds, &experimentIdProto);
342
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800343 event->updateValue(6 /*experiment ids field id*/, experimentIdProto, STORAGE);
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800344}
345
346vector<int64_t> StatsLogProcessor::processWatchdogRollbackOccurred(const int32_t rollbackTypeIn,
347 const string& packageNameIn) {
348 // If the package name is empty, we can't attribute it to any train, so
349 // return early.
350 if (packageNameIn.empty()) {
351 return vector<int64_t>();
352 }
353 bool readTrainInfoSuccess = false;
354 InstallTrainInfo trainInfoOnDisk;
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800355 // We use the package name of the event as the train name.
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800356 readTrainInfoSuccess = StorageManager::readTrainInfo(packageNameIn, trainInfoOnDisk);
357
358 if (!readTrainInfoSuccess) {
359 return vector<int64_t>();
360 }
361
362 if (trainInfoOnDisk.experimentIds.empty()) {
363 return vector<int64_t>();
364 }
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800365
366 int64_t firstId = trainInfoOnDisk.experimentIds[0];
367 auto& ids = trainInfoOnDisk.experimentIds;
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800368 switch (rollbackTypeIn) {
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800369 case android::os::statsd::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_INITIATE:
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800370 if (find(ids.begin(), ids.end(), firstId + 4) == ids.end()) {
371 ids.push_back(firstId + 4);
372 }
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800373 StorageManager::writeTrainInfo(trainInfoOnDisk);
374 break;
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800375 case android::os::statsd::util::WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_TYPE__ROLLBACK_SUCCESS:
Jonathan Nguyen727a9642020-02-12 17:24:32 -0800376 if (find(ids.begin(), ids.end(), firstId + 5) == ids.end()) {
377 ids.push_back(firstId + 5);
378 }
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800379 StorageManager::writeTrainInfo(trainInfoOnDisk);
380 break;
381 }
382
383 return trainInfoOnDisk.experimentIds;
384}
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800385
Yangster-mac892f3d32018-05-02 14:16:48 -0700386void StatsLogProcessor::resetConfigs() {
387 std::lock_guard<std::mutex> lock(mMetricsMutex);
388 resetConfigsLocked(getElapsedRealtimeNs());
389}
390
391void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) {
392 std::vector<ConfigKey> configKeys;
393 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
394 configKeys.push_back(it->first);
395 }
396 resetConfigsLocked(timestampNs, configKeys);
397}
398
Yao Chen3ff3a492018-08-06 16:17:37 -0700399void StatsLogProcessor::OnLogEvent(LogEvent* event) {
Tej Singh480392f2019-10-23 15:53:46 -0700400 OnLogEvent(event, getElapsedRealtimeNs());
401}
402
403void StatsLogProcessor::OnLogEvent(LogEvent* event, int64_t elapsedRealtimeNs) {
Yangster-macd40053e2018-01-09 16:29:22 -0800404 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yao Chen876889c2018-05-02 11:16:16 -0700405
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800406 // Hard-coded logic to update train info on disk and fill in any information
407 // this log event may be missing.
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800408 if (event->GetTagId() == android::os::statsd::util::BINARY_PUSH_STATE_CHANGED) {
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800409 onBinaryPushStateChangedEventLocked(event);
410 }
411
412 // Hard-coded logic to update experiment ids on disk for certain rollback
413 // types and fill the rollback atom with experiment ids
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800414 if (event->GetTagId() == android::os::statsd::util::WATCHDOG_ROLLBACK_OCCURRED) {
Jonathan Nguyen703c42f2020-02-04 15:54:26 -0800415 onWatchdogRollbackOccurredLocked(event);
Jonathan Nguyena0e6de12020-01-28 18:33:55 -0800416 }
417
Yao Chen876889c2018-05-02 11:16:16 -0700418#ifdef VERY_VERBOSE_PRINTING
419 if (mPrintAllLogs) {
420 ALOGI("%s", event->ToString().c_str());
421 }
422#endif
Tej Singh480392f2019-10-23 15:53:46 -0700423 const int64_t eventElapsedTimeNs = event->GetElapsedTimestampNs();
Yangster-macb8382a12018-04-04 10:39:12 -0700424
Tej Singh480392f2019-10-23 15:53:46 -0700425 resetIfConfigTtlExpiredLocked(eventElapsedTimeNs);
Yangster-macb142cc82018-03-30 15:22:08 -0700426
Yangster-macd40053e2018-01-09 16:29:22 -0800427 StatsdStats::getInstance().noteAtomLogged(
Yangster-mac330af582018-02-08 15:24:38 -0800428 event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC);
Yangster-macd40053e2018-01-09 16:29:22 -0800429
David Chen21582962017-11-01 17:32:46 -0700430 // Hard-coded logic to update the isolated uid's in the uid-map.
Stefan Lafonae2df012017-11-14 09:17:21 -0800431 // The field numbers need to be currently updated by hand with atoms.proto
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800432 if (event->GetTagId() == android::os::statsd::util::ISOLATED_UID_CHANGED) {
Yangster-macd40053e2018-01-09 16:29:22 -0800433 onIsolatedUidChangedEventLocked(*event);
David Chencfc311d2018-01-23 17:55:54 -0800434 }
435
tsaichristined21aacf2019-10-07 14:47:38 -0700436 StateManager::getInstance().onLogEvent(*event);
437
David Chencfc311d2018-01-23 17:55:54 -0800438 if (mMetricsManagers.empty()) {
439 return;
440 }
441
Yangster-macb142cc82018-03-30 15:22:08 -0700442 int64_t curTimeSec = getElapsedRealtimeSec();
Yangster-mac330af582018-02-08 15:24:38 -0800443 if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
Chenjie Yue2219202018-06-08 10:07:51 -0700444 mPullerManager->ClearPullerCacheIfNecessary(curTimeSec * NS_PER_SEC);
Yangster-mac330af582018-02-08 15:24:38 -0800445 mLastPullerCacheClearTimeSec = curTimeSec;
Chenjie Yufa22d652018-02-05 14:37:48 -0800446 }
447
Yangster-macb142cc82018-03-30 15:22:08 -0700448
Jeffrey Huang74fc4352020-03-06 15:18:33 -0800449 if (event->GetTagId() != android::os::statsd::util::ISOLATED_UID_CHANGED) {
Yangster-macd40053e2018-01-09 16:29:22 -0800450 // Map the isolated uid to host uid if necessary.
451 mapIsolatedUidToHostUidIfNecessaryLocked(event);
452 }
453
Tej Singh6ede28b2019-01-29 17:06:54 -0800454 std::unordered_set<int> uidsWithActiveConfigsChanged;
455 std::unordered_map<int, std::vector<int64_t>> activeConfigsPerUid;
Yangster-macd40053e2018-01-09 16:29:22 -0800456 // pass the event to metrics managers.
457 for (auto& pair : mMetricsManagers) {
Tej Singh6ede28b2019-01-29 17:06:54 -0800458 int uid = pair.first.GetUid();
459 int64_t configId = pair.first.GetId();
460 bool isPrevActive = pair.second->isActive();
Yangster-macd40053e2018-01-09 16:29:22 -0800461 pair.second->onLogEvent(*event);
Tej Singh6ede28b2019-01-29 17:06:54 -0800462 bool isCurActive = pair.second->isActive();
463 // Map all active configs by uid.
464 if (isCurActive) {
465 auto activeConfigs = activeConfigsPerUid.find(uid);
466 if (activeConfigs != activeConfigsPerUid.end()) {
467 activeConfigs->second.push_back(configId);
468 } else {
469 vector<int64_t> newActiveConfigs;
470 newActiveConfigs.push_back(configId);
471 activeConfigsPerUid[uid] = newActiveConfigs;
472 }
473 }
474 // The activation state of this config changed.
475 if (isPrevActive != isCurActive) {
476 VLOG("Active status changed for uid %d", uid);
477 uidsWithActiveConfigsChanged.insert(uid);
478 StatsdStats::getInstance().noteActiveStatusChanged(pair.first, isCurActive);
479 }
Tej Singh480392f2019-10-23 15:53:46 -0700480 flushIfNecessaryLocked(pair.first, *(pair.second));
David Chen21582962017-11-01 17:32:46 -0700481 }
Tej Singh6ede28b2019-01-29 17:06:54 -0800482
Tej Singh480392f2019-10-23 15:53:46 -0700483 // Don't use the event timestamp for the guardrail.
Tej Singh6ede28b2019-01-29 17:06:54 -0800484 for (int uid : uidsWithActiveConfigsChanged) {
485 // Send broadcast so that receivers can pull data.
486 auto lastBroadcastTime = mLastActivationBroadcastTimes.find(uid);
487 if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) {
Tej Singh480392f2019-10-23 15:53:46 -0700488 if (elapsedRealtimeNs - lastBroadcastTime->second <
489 StatsdStats::kMinActivationBroadcastPeriodNs) {
Tej Singh16ca28f2019-06-24 11:58:23 -0700490 StatsdStats::getInstance().noteActivationBroadcastGuardrailHit(uid);
Tej Singh6ede28b2019-01-29 17:06:54 -0800491 VLOG("StatsD would've sent an activation broadcast but the rate limit stopped us.");
492 return;
493 }
494 }
495 auto activeConfigs = activeConfigsPerUid.find(uid);
496 if (activeConfigs != activeConfigsPerUid.end()) {
497 if (mSendActivationBroadcast(uid, activeConfigs->second)) {
498 VLOG("StatsD sent activation notice for uid %d", uid);
Tej Singh480392f2019-10-23 15:53:46 -0700499 mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
Tej Singh6ede28b2019-01-29 17:06:54 -0800500 }
501 } else {
502 std::vector<int64_t> emptyActiveConfigs;
503 if (mSendActivationBroadcast(uid, emptyActiveConfigs)) {
504 VLOG("StatsD sent EMPTY activation notice for uid %d", uid);
Tej Singh480392f2019-10-23 15:53:46 -0700505 mLastActivationBroadcastTimes[uid] = elapsedRealtimeNs;
Tej Singh6ede28b2019-01-29 17:06:54 -0800506 }
507 }
508 }
509}
510
511void StatsLogProcessor::GetActiveConfigs(const int uid, vector<int64_t>& outActiveConfigs) {
512 std::lock_guard<std::mutex> lock(mMetricsMutex);
513 GetActiveConfigsLocked(uid, outActiveConfigs);
514}
515
516void StatsLogProcessor::GetActiveConfigsLocked(const int uid, vector<int64_t>& outActiveConfigs) {
517 outActiveConfigs.clear();
518 for (auto& pair : mMetricsManagers) {
519 if (pair.first.GetUid() == uid && pair.second->isActive()) {
520 outActiveConfigs.push_back(pair.first.GetId());
521 }
522 }
Yao Chenab273e22017-09-06 12:53:50 -0700523}
524
Yangster-macc04feba2018-04-02 14:37:33 -0700525void StatsLogProcessor::OnConfigUpdated(const int64_t timestampNs, const ConfigKey& key,
526 const StatsdConfig& config) {
Yangster-macb0d06282018-01-05 15:44:07 -0800527 std::lock_guard<std::mutex> lock(mMetricsMutex);
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000528 WriteDataToDiskLocked(key, timestampNs, CONFIG_UPDATED, NO_TIME_CONSTRAINTS);
Yangster-macb142cc82018-03-30 15:22:08 -0700529 OnConfigUpdatedLocked(timestampNs, key, config);
530}
531
532void StatsLogProcessor::OnConfigUpdatedLocked(
533 const int64_t timestampNs, const ConfigKey& key, const StatsdConfig& config) {
Tej Singh484524a2018-02-01 15:10:05 -0800534 VLOG("Updated configuration for key %s", key.ToString().c_str());
Yangster-mac932ecec2018-02-01 10:23:52 -0800535 sp<MetricsManager> newMetricsManager =
Chenjie Yue2219202018-06-08 10:07:51 -0700536 new MetricsManager(key, config, mTimeBaseNs, timestampNs, mUidMap, mPullerManager,
537 mAnomalyAlarmMonitor, mPeriodicAlarmMonitor);
Yao Chencaf339d2017-10-06 16:01:10 -0700538 if (newMetricsManager->isConfigValid()) {
David Chend6896892017-10-25 11:49:03 -0700539 mUidMap->OnConfigUpdated(key);
Yangster-macb142cc82018-03-30 15:22:08 -0700540 newMetricsManager->refreshTtl(timestampNs);
Yao Chend10f7b12017-12-18 12:53:50 -0800541 mMetricsManagers[key] = newMetricsManager;
Yao Chenb3561512017-11-21 18:07:17 -0800542 VLOG("StatsdConfig valid");
Yao Chencaf339d2017-10-06 16:01:10 -0700543 } else {
544 // If there is any error in the config, don't use it.
Yao Chenb3561512017-11-21 18:07:17 -0800545 ALOGE("StatsdConfig NOT valid");
Yao Chencaf339d2017-10-06 16:01:10 -0700546 }
yro00698da2017-09-15 10:06:40 -0700547}
Bookatz906a35c2017-09-20 15:26:44 -0700548
Yangster7c334a12017-11-22 14:24:24 -0800549size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const {
Yangster-macb0d06282018-01-05 15:44:07 -0800550 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yao Chen729093d2017-10-16 10:33:26 -0700551 auto it = mMetricsManagers.find(key);
552 if (it == mMetricsManagers.end()) {
553 ALOGW("Config source %s does not exist", key.ToString().c_str());
David Chen1d7b0cd2017-11-15 14:20:04 -0800554 return 0;
Yao Chen729093d2017-10-16 10:33:26 -0700555 }
David Chen1d7b0cd2017-11-15 14:20:04 -0800556 return it->second->byteSize();
557}
558
Yao Chena80e5c02018-09-04 13:55:29 -0700559void StatsLogProcessor::dumpStates(int out, bool verbose) {
Yao Chen884c8c12018-01-26 10:36:25 -0800560 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yao Chena80e5c02018-09-04 13:55:29 -0700561 FILE* fout = fdopen(out, "w");
562 if (fout == NULL) {
563 return;
Yao Chen884c8c12018-01-26 10:36:25 -0800564 }
Yao Chena80e5c02018-09-04 13:55:29 -0700565 fprintf(fout, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size());
566 for (auto metricsManager : mMetricsManagers) {
567 metricsManager.second->dumpStates(fout, verbose);
568 }
569
570 fclose(fout);
Yao Chen884c8c12018-01-26 10:36:25 -0800571}
572
yro4beccbe2018-03-15 19:42:05 -0700573/*
Bookatz9cc7b662018-11-06 10:39:21 -0800574 * onDumpReport dumps serialized ConfigMetricsReportList into proto.
yro4beccbe2018-03-15 19:42:05 -0700575 */
Yangster-macb142cc82018-03-30 15:22:08 -0700576void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
Yangster-mace68f3a52018-04-04 00:01:43 -0700577 const bool include_current_partial_bucket,
Bookatzff71cad2018-09-20 17:17:49 -0700578 const bool erase_data,
Chenjie Yue36018b2018-04-16 15:18:30 -0700579 const DumpReportReason dumpReportReason,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000580 const DumpLatency dumpLatency,
Bookatzff71cad2018-09-20 17:17:49 -0700581 ProtoOutputStream* proto) {
Yangster-macb0d06282018-01-05 15:44:07 -0800582 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yangster-mac20877162017-12-22 17:19:39 -0800583
yro947fbce2017-11-15 22:50:23 -0800584 // Start of ConfigKey.
Bookatzff71cad2018-09-20 17:17:49 -0700585 uint64_t configKeyToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY);
586 proto->write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid());
587 proto->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId());
588 proto->end(configKeyToken);
yro947fbce2017-11-15 22:50:23 -0800589 // End of ConfigKey.
yro17adac92017-11-08 23:16:29 -0800590
Yao Chen9a43b4f2019-04-10 10:43:20 -0700591 bool keepFile = false;
592 auto it = mMetricsManagers.find(key);
593 if (it != mMetricsManagers.end() && it->second->shouldPersistLocalHistory()) {
594 keepFile = true;
595 }
596
yro947fbce2017-11-15 22:50:23 -0800597 // Then, check stats-data directory to see there's any file containing
598 // ConfigMetricsReport from previous shutdowns to concatenate to reports.
Yao Chen9a43b4f2019-04-10 10:43:20 -0700599 StorageManager::appendConfigMetricsReport(
600 key, proto, erase_data && !keepFile /* should remove file after appending it */,
601 dumpReportReason == ADB_DUMP /*if caller is adb*/);
yro947fbce2017-11-15 22:50:23 -0800602
Yangster-mace68f3a52018-04-04 00:01:43 -0700603 if (it != mMetricsManagers.end()) {
604 // This allows another broadcast to be sent within the rate-limit period if we get close to
605 // filling the buffer again soon.
606 mLastBroadcastTimes.erase(key);
607
Yao Chen9a43b4f2019-04-10 10:43:20 -0700608 vector<uint8_t> buffer;
609 onConfigMetricsReportLocked(key, dumpTimeStampNs, include_current_partial_bucket,
610 erase_data, dumpReportReason, dumpLatency,
611 false /* is this data going to be saved on disk */, &buffer);
612 proto->write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS,
613 reinterpret_cast<char*>(buffer.data()), buffer.size());
Yangster-mace68f3a52018-04-04 00:01:43 -0700614 } else {
615 ALOGW("Config source %s does not exist", key.ToString().c_str());
616 }
Bookatzff71cad2018-09-20 17:17:49 -0700617}
618
619/*
620 * onDumpReport dumps serialized ConfigMetricsReportList into outData.
621 */
622void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
623 const bool include_current_partial_bucket,
624 const bool erase_data,
625 const DumpReportReason dumpReportReason,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000626 const DumpLatency dumpLatency,
Bookatzff71cad2018-09-20 17:17:49 -0700627 vector<uint8_t>* outData) {
628 ProtoOutputStream proto;
629 onDumpReport(key, dumpTimeStampNs, include_current_partial_bucket, erase_data,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000630 dumpReportReason, dumpLatency, &proto);
Yangster-mace68f3a52018-04-04 00:01:43 -0700631
David Chen1d7b0cd2017-11-15 14:20:04 -0800632 if (outData != nullptr) {
Yao Chen9a43b4f2019-04-10 10:43:20 -0700633 flushProtoToBuffer(proto, outData);
634 VLOG("output data size %zu", outData->size());
yro17adac92017-11-08 23:16:29 -0800635 }
Yao Chen8a8d16c2018-02-08 14:50:40 -0800636
Yangster-mace68f3a52018-04-04 00:01:43 -0700637 StatsdStats::getInstance().noteMetricsReportSent(key, proto.size());
Yao Chen729093d2017-10-16 10:33:26 -0700638}
639
yro4beccbe2018-03-15 19:42:05 -0700640/*
641 * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData.
642 */
Yao Chen9a43b4f2019-04-10 10:43:20 -0700643void StatsLogProcessor::onConfigMetricsReportLocked(
644 const ConfigKey& key, const int64_t dumpTimeStampNs,
645 const bool include_current_partial_bucket, const bool erase_data,
646 const DumpReportReason dumpReportReason, const DumpLatency dumpLatency,
647 const bool dataSavedOnDisk, vector<uint8_t>* buffer) {
yro4beccbe2018-03-15 19:42:05 -0700648 // We already checked whether key exists in mMetricsManagers in
649 // WriteDataToDisk.
650 auto it = mMetricsManagers.find(key);
Yangster-mace68f3a52018-04-04 00:01:43 -0700651 if (it == mMetricsManagers.end()) {
652 return;
653 }
yro4beccbe2018-03-15 19:42:05 -0700654 int64_t lastReportTimeNs = it->second->getLastReportTimeNs();
655 int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs();
656
Yangster-mac9def8e32018-04-17 13:55:51 -0700657 std::set<string> str_set;
658
Yao Chen9a43b4f2019-04-10 10:43:20 -0700659 ProtoOutputStream tempProto;
yro4beccbe2018-03-15 19:42:05 -0700660 // First, fill in ConfigMetricsReport using current data on memory, which
661 // starts from filling in StatsLogReport's.
Yao Chen9a43b4f2019-04-10 10:43:20 -0700662 it->second->onDumpReport(dumpTimeStampNs, include_current_partial_bucket, erase_data,
663 dumpLatency, &str_set, &tempProto);
yro4beccbe2018-03-15 19:42:05 -0700664
David Chen9e6dbbd2018-05-07 17:52:29 -0700665 // Fill in UidMap if there is at least one metric to report.
666 // This skips the uid map if it's an empty config.
667 if (it->second->getNumMetrics() > 0) {
Yao Chen9a43b4f2019-04-10 10:43:20 -0700668 uint64_t uidMapToken = tempProto.start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP);
dwchen730403e2018-10-29 11:41:56 -0700669 mUidMap->appendUidMap(
670 dumpTimeStampNs, key, it->second->hashStringInReport() ? &str_set : nullptr,
Yao Chen9a43b4f2019-04-10 10:43:20 -0700671 it->second->versionStringsInReport(), it->second->installerInReport(), &tempProto);
672 tempProto.end(uidMapToken);
David Chen9e6dbbd2018-05-07 17:52:29 -0700673 }
yro4beccbe2018-03-15 19:42:05 -0700674
675 // Fill in the timestamps.
Yao Chen9a43b4f2019-04-10 10:43:20 -0700676 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS,
677 (long long)lastReportTimeNs);
678 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS,
679 (long long)dumpTimeStampNs);
680 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS,
681 (long long)lastReportWallClockNs);
682 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS,
683 (long long)getWallClockNs());
Chenjie Yue36018b2018-04-16 15:18:30 -0700684 // Dump report reason
Yao Chen9a43b4f2019-04-10 10:43:20 -0700685 tempProto.write(FIELD_TYPE_INT32 | FIELD_ID_DUMP_REPORT_REASON, dumpReportReason);
Yangster-mac9def8e32018-04-17 13:55:51 -0700686
David Chen56ae0d92018-05-11 16:00:22 -0700687 for (const auto& str : str_set) {
Yao Chen9a43b4f2019-04-10 10:43:20 -0700688 tempProto.write(FIELD_TYPE_STRING | FIELD_COUNT_REPEATED | FIELD_ID_STRINGS, str);
689 }
690
691 flushProtoToBuffer(tempProto, buffer);
692
693 // save buffer to disk if needed
694 if (erase_data && !dataSavedOnDisk && it->second->shouldPersistLocalHistory()) {
695 VLOG("save history to disk");
696 string file_name = StorageManager::getDataHistoryFileName((long)getWallClockSec(),
697 key.GetUid(), key.GetId());
698 StorageManager::writeFile(file_name.c_str(), buffer->data(), buffer->size());
Yangster-mac9def8e32018-04-17 13:55:51 -0700699 }
Yangster-macb142cc82018-03-30 15:22:08 -0700700}
yro4beccbe2018-03-15 19:42:05 -0700701
Yao Chen163d2602018-04-10 10:39:53 -0700702void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs,
703 const std::vector<ConfigKey>& configs) {
704 for (const auto& key : configs) {
Yangster-macb142cc82018-03-30 15:22:08 -0700705 StatsdConfig config;
706 if (StorageManager::readConfigFromDisk(key, &config)) {
707 OnConfigUpdatedLocked(timestampNs, key, config);
708 StatsdStats::getInstance().noteConfigReset(key);
709 } else {
710 ALOGE("Failed to read backup config from disk for : %s", key.ToString().c_str());
711 auto it = mMetricsManagers.find(key);
712 if (it != mMetricsManagers.end()) {
713 it->second->refreshTtl(timestampNs);
714 }
715 }
716 }
yro4beccbe2018-03-15 19:42:05 -0700717}
718
Yao Chen163d2602018-04-10 10:39:53 -0700719void StatsLogProcessor::resetIfConfigTtlExpiredLocked(const int64_t timestampNs) {
720 std::vector<ConfigKey> configKeysTtlExpired;
721 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
722 if (it->second != nullptr && !it->second->isInTtl(timestampNs)) {
723 configKeysTtlExpired.push_back(it->first);
724 }
725 }
726 if (configKeysTtlExpired.size() > 0) {
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000727 WriteDataToDiskLocked(CONFIG_RESET, NO_TIME_CONSTRAINTS);
Yao Chen163d2602018-04-10 10:39:53 -0700728 resetConfigsLocked(timestampNs, configKeysTtlExpired);
729 }
730}
731
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700732void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
Yangster-macb0d06282018-01-05 15:44:07 -0800733 std::lock_guard<std::mutex> lock(mMetricsMutex);
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700734 auto it = mMetricsManagers.find(key);
735 if (it != mMetricsManagers.end()) {
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700736 WriteDataToDiskLocked(key, getElapsedRealtimeNs(), CONFIG_REMOVED,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000737 NO_TIME_CONSTRAINTS);
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700738 mMetricsManagers.erase(it);
David Chend6896892017-10-25 11:49:03 -0700739 mUidMap->OnConfigRemoved(key);
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700740 }
Yao Chenb3561512017-11-21 18:07:17 -0800741 StatsdStats::getInstance().noteConfigRemoved(key);
David Chen1d7b0cd2017-11-15 14:20:04 -0800742
David Chen1d7b0cd2017-11-15 14:20:04 -0800743 mLastBroadcastTimes.erase(key);
Chenjie Yufa22d652018-02-05 14:37:48 -0800744
Tej Singh6ede28b2019-01-29 17:06:54 -0800745 int uid = key.GetUid();
746 bool lastConfigForUid = true;
747 for (auto it : mMetricsManagers) {
748 if (it.first.GetUid() == uid) {
749 lastConfigForUid = false;
750 break;
751 }
752 }
753 if (lastConfigForUid) {
754 mLastActivationBroadcastTimes.erase(uid);
755 }
756
Chenjie Yufa22d652018-02-05 14:37:48 -0800757 if (mMetricsManagers.empty()) {
Chenjie Yue2219202018-06-08 10:07:51 -0700758 mPullerManager->ForceClearPullerCache();
Chenjie Yufa22d652018-02-05 14:37:48 -0800759 }
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700760}
761
Tej Singh480392f2019-10-23 15:53:46 -0700762void StatsLogProcessor::flushIfNecessaryLocked(const ConfigKey& key,
763 MetricsManager& metricsManager) {
764 int64_t elapsedRealtimeNs = getElapsedRealtimeNs();
David Chend9269e22017-12-05 13:43:51 -0800765 auto lastCheckTime = mLastByteSizeTimes.find(key);
766 if (lastCheckTime != mLastByteSizeTimes.end()) {
Tej Singh480392f2019-10-23 15:53:46 -0700767 if (elapsedRealtimeNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
David Chend9269e22017-12-05 13:43:51 -0800768 return;
769 }
770 }
771
772 // We suspect that the byteSize() computation is expensive, so we set a rate limit.
773 size_t totalBytes = metricsManager.byteSize();
Tej Singh480392f2019-10-23 15:53:46 -0700774 mLastByteSizeTimes[key] = elapsedRealtimeNs;
David Chen48944902018-05-03 10:29:11 -0700775 bool requestDump = false;
Tej Singh480392f2019-10-23 15:53:46 -0700776 if (totalBytes > StatsdStats::kMaxMetricsBytesPerConfig) {
777 // Too late. We need to start clearing data.
778 metricsManager.dropData(elapsedRealtimeNs);
Chenjie Yuc3c30c02018-10-26 09:48:07 -0700779 StatsdStats::getInstance().noteDataDropped(key, totalBytes);
David Chen12942952017-12-04 14:28:43 -0800780 VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
David Chen48944902018-05-03 10:29:11 -0700781 } else if ((totalBytes > StatsdStats::kBytesPerConfigTriggerGetData) ||
782 (mOnDiskDataConfigs.find(key) != mOnDiskDataConfigs.end())) {
783 // Request to send a broadcast if:
784 // 1. in memory data > threshold OR
785 // 2. config has old data report on disk.
786 requestDump = true;
787 }
788
789 if (requestDump) {
David Chend9269e22017-12-05 13:43:51 -0800790 // Send broadcast so that receivers can pull data.
791 auto lastBroadcastTime = mLastBroadcastTimes.find(key);
792 if (lastBroadcastTime != mLastBroadcastTimes.end()) {
Tej Singh480392f2019-10-23 15:53:46 -0700793 if (elapsedRealtimeNs - lastBroadcastTime->second <
794 StatsdStats::kMinBroadcastPeriodNs) {
David Chend9269e22017-12-05 13:43:51 -0800795 VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
David Chen1d7b0cd2017-11-15 14:20:04 -0800796 return;
797 }
798 }
David Chen48944902018-05-03 10:29:11 -0700799 if (mSendBroadcast(key)) {
800 mOnDiskDataConfigs.erase(key);
801 VLOG("StatsD triggered data fetch for %s", key.ToString().c_str());
Tej Singh480392f2019-10-23 15:53:46 -0700802 mLastBroadcastTimes[key] = elapsedRealtimeNs;
David Chen48944902018-05-03 10:29:11 -0700803 StatsdStats::getInstance().noteBroadcastSent(key);
804 }
yro31eb67b2017-10-24 13:33:21 -0700805 }
806}
807
Chenjie Yue36018b2018-04-16 15:18:30 -0700808void StatsLogProcessor::WriteDataToDiskLocked(const ConfigKey& key,
Yangster-mac892f3d32018-05-02 14:16:48 -0700809 const int64_t timestampNs,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000810 const DumpReportReason dumpReportReason,
811 const DumpLatency dumpLatency) {
yro028091c2018-05-09 16:03:27 -0700812 if (mMetricsManagers.find(key) == mMetricsManagers.end() ||
813 !mMetricsManagers.find(key)->second->shouldWriteToDisk()) {
Yangster-mac892f3d32018-05-02 14:16:48 -0700814 return;
815 }
Yao Chen9a43b4f2019-04-10 10:43:20 -0700816 vector<uint8_t> buffer;
David Chen56ae0d92018-05-11 16:00:22 -0700817 onConfigMetricsReportLocked(key, timestampNs, true /* include_current_partial_bucket*/,
Yao Chen9a43b4f2019-04-10 10:43:20 -0700818 true /* erase_data */, dumpReportReason, dumpLatency, true,
819 &buffer);
820 string file_name =
821 StorageManager::getDataFileName((long)getWallClockSec(), key.GetUid(), key.GetId());
822 StorageManager::writeFile(file_name.c_str(), buffer.data(), buffer.size());
823
David Chen48944902018-05-03 10:29:11 -0700824 // We were able to write the ConfigMetricsReport to disk, so we should trigger collection ASAP.
825 mOnDiskDataConfigs.insert(key);
Yangster-mace68f3a52018-04-04 00:01:43 -0700826}
827
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700828void StatsLogProcessor::SaveActiveConfigsToDisk(int64_t currentTimeNs) {
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800829 std::lock_guard<std::mutex> lock(mMetricsMutex);
jianjin996f40d2019-03-29 13:53:48 -0700830 const int64_t timeNs = getElapsedRealtimeNs();
831 // Do not write to disk if we already have in the last few seconds.
jianjin996f40d2019-03-29 13:53:48 -0700832 if (static_cast<unsigned long long> (timeNs) <
833 mLastActiveMetricsWriteNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
834 ALOGI("Statsd skipping writing active metrics to disk. Already wrote data in last %d seconds",
835 WRITE_DATA_COOL_DOWN_SEC);
836 return;
837 }
838 mLastActiveMetricsWriteNs = timeNs;
839
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800840 ProtoOutputStream proto;
Tej Singhf53d4452019-05-09 18:17:59 -0700841 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, DEVICE_SHUTDOWN, &proto);
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800842
843 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
844 StorageManager::deleteFile(file_name.c_str());
845 android::base::unique_fd fd(
846 open(file_name.c_str(), O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR));
847 if (fd == -1) {
848 ALOGE("Attempt to write %s but failed", file_name.c_str());
849 return;
850 }
851 proto.flush(fd.get());
852}
853
Tej Singhf53d4452019-05-09 18:17:59 -0700854void StatsLogProcessor::WriteActiveConfigsToProtoOutputStream(
855 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) {
856 std::lock_guard<std::mutex> lock(mMetricsMutex);
857 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, reason, proto);
858}
859
860void StatsLogProcessor::WriteActiveConfigsToProtoOutputStreamLocked(
861 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) {
862 for (const auto& pair : mMetricsManagers) {
863 const sp<MetricsManager>& metricsManager = pair.second;
864 uint64_t configToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED |
865 FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG);
866 metricsManager->writeActiveConfigToProtoOutputStream(currentTimeNs, reason, proto);
867 proto->end(configToken);
868 }
869}
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700870void StatsLogProcessor::LoadActiveConfigsFromDisk() {
871 std::lock_guard<std::mutex> lock(mMetricsMutex);
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800872 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
873 int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC);
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700874 if (-1 == fd) {
875 VLOG("Attempt to read %s but failed", file_name.c_str());
876 StorageManager::deleteFile(file_name.c_str());
877 return;
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800878 }
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700879 string content;
880 if (!android::base::ReadFdToString(fd, &content)) {
881 ALOGE("Attempt to read %s but failed", file_name.c_str());
882 close(fd);
883 StorageManager::deleteFile(file_name.c_str());
884 return;
885 }
886
887 close(fd);
888
889 ActiveConfigList activeConfigList;
890 if (!activeConfigList.ParseFromString(content)) {
891 ALOGE("Attempt to read %s but failed; failed to load active configs", file_name.c_str());
892 StorageManager::deleteFile(file_name.c_str());
893 return;
894 }
Tej Singhf53d4452019-05-09 18:17:59 -0700895 // Passing in mTimeBaseNs only works as long as we only load from disk is when statsd starts.
896 SetConfigsActiveStateLocked(activeConfigList, mTimeBaseNs);
897 StorageManager::deleteFile(file_name.c_str());
898}
899
900void StatsLogProcessor::SetConfigsActiveState(const ActiveConfigList& activeConfigList,
901 int64_t currentTimeNs) {
902 std::lock_guard<std::mutex> lock(mMetricsMutex);
903 SetConfigsActiveStateLocked(activeConfigList, currentTimeNs);
904}
905
906void StatsLogProcessor::SetConfigsActiveStateLocked(const ActiveConfigList& activeConfigList,
907 int64_t currentTimeNs) {
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700908 for (int i = 0; i < activeConfigList.config_size(); i++) {
909 const auto& config = activeConfigList.config(i);
910 ConfigKey key(config.uid(), config.id());
911 auto it = mMetricsManagers.find(key);
912 if (it == mMetricsManagers.end()) {
913 ALOGE("No config found for config %s", key.ToString().c_str());
914 continue;
915 }
916 VLOG("Setting active config %s", key.ToString().c_str());
Tej Singhf53d4452019-05-09 18:17:59 -0700917 it->second->loadActiveConfig(config, currentTimeNs);
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700918 }
919 VLOG("Successfully loaded %d active configs.", activeConfigList.config_size());
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800920}
921
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000922void StatsLogProcessor::WriteDataToDiskLocked(const DumpReportReason dumpReportReason,
923 const DumpLatency dumpLatency) {
Yangster-mac892f3d32018-05-02 14:16:48 -0700924 const int64_t timeNs = getElapsedRealtimeNs();
Tej Singh42f9e062018-11-09 10:01:00 -0800925 // Do not write to disk if we already have in the last few seconds.
926 // This is to avoid overwriting files that would have the same name if we
927 // write twice in the same second.
928 if (static_cast<unsigned long long> (timeNs) <
929 mLastWriteTimeNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
930 ALOGI("Statsd skipping writing data to disk. Already wrote data in last %d seconds",
931 WRITE_DATA_COOL_DOWN_SEC);
932 return;
933 }
934 mLastWriteTimeNs = timeNs;
Yangster-mace68f3a52018-04-04 00:01:43 -0700935 for (auto& pair : mMetricsManagers) {
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000936 WriteDataToDiskLocked(pair.first, timeNs, dumpReportReason, dumpLatency);
Yangster-mace68f3a52018-04-04 00:01:43 -0700937 }
938}
939
Muhammad Qureshi844694b2019-04-05 10:10:40 -0700940void StatsLogProcessor::WriteDataToDisk(const DumpReportReason dumpReportReason,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000941 const DumpLatency dumpLatency) {
Yangster-macb0d06282018-01-05 15:44:07 -0800942 std::lock_guard<std::mutex> lock(mMetricsMutex);
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000943 WriteDataToDiskLocked(dumpReportReason, dumpLatency);
yro947fbce2017-11-15 22:50:23 -0800944}
945
Yangster-mac15f6bbc2018-04-08 11:52:26 -0700946void StatsLogProcessor::informPullAlarmFired(const int64_t timestampNs) {
Yangster6df5fcc2018-04-12 11:04:29 -0700947 std::lock_guard<std::mutex> lock(mMetricsMutex);
Chenjie Yue2219202018-06-08 10:07:51 -0700948 mPullerManager->OnAlarmFired(timestampNs);
Yangster-mac15f6bbc2018-04-08 11:52:26 -0700949}
950
David Chend37bc232018-04-12 18:05:11 -0700951int64_t StatsLogProcessor::getLastReportTimeNs(const ConfigKey& key) {
952 auto it = mMetricsManagers.find(key);
953 if (it == mMetricsManagers.end()) {
954 return 0;
955 } else {
956 return it->second->getLastReportTimeNs();
957 }
958}
959
Tej Singh9ec159a2019-11-14 11:59:48 -0800960void StatsLogProcessor::notifyAppUpgrade(const int64_t& eventTimeNs, const string& apk,
961 const int uid, const int64_t version) {
962 std::lock_guard<std::mutex> lock(mMetricsMutex);
963 ALOGW("Received app upgrade");
964 for (auto it : mMetricsManagers) {
965 it.second->notifyAppUpgrade(eventTimeNs, apk, uid, version);
966 }
967}
968
969void StatsLogProcessor::notifyAppRemoved(const int64_t& eventTimeNs, const string& apk,
970 const int uid) {
971 std::lock_guard<std::mutex> lock(mMetricsMutex);
972 ALOGW("Received app removed");
973 for (auto it : mMetricsManagers) {
974 it.second->notifyAppRemoved(eventTimeNs, apk, uid);
975 }
976}
977
978void StatsLogProcessor::onUidMapReceived(const int64_t& eventTimeNs) {
979 std::lock_guard<std::mutex> lock(mMetricsMutex);
980 ALOGW("Received uid map");
981 for (auto it : mMetricsManagers) {
982 it.second->onUidMapReceived(eventTimeNs);
983 }
984}
985
David Chen48944902018-05-03 10:29:11 -0700986void StatsLogProcessor::noteOnDiskData(const ConfigKey& key) {
987 std::lock_guard<std::mutex> lock(mMetricsMutex);
988 mOnDiskDataConfigs.insert(key);
989}
990
Yao Chenef99c4f2017-09-22 16:26:54 -0700991} // namespace statsd
992} // namespace os
993} // namespace android