blob: 286e76ec108a760dcddec904556b039047be620b [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"
David Chen21582962017-11-01 17:32:46 -070019#include "statslog.h"
Yao Chenab273e22017-09-06 12:53:50 -070020
yro947fbce2017-11-15 22:50:23 -080021#include <android-base/file.h>
22#include <dirent.h>
Chenjie Yuc7939cb2019-02-04 17:25:45 -080023#include <frameworks/base/cmds/statsd/src/active_config_list.pb.h>
Joe Onorato9fc9edf2017-10-15 20:08:52 -070024#include "StatsLogProcessor.h"
yro947fbce2017-11-15 22:50:23 -080025#include "android-base/stringprintf.h"
Chenjie Yuc7939cb2019-02-04 17:25:45 -080026#include "external/StatsPullerManager.h"
Yao Chenb3561512017-11-21 18:07:17 -080027#include "guardrail/StatsdStats.h"
Joe Onorato9fc9edf2017-10-15 20:08:52 -070028#include "metrics/CountMetricProducer.h"
Chenjie Yuc7939cb2019-02-04 17:25:45 -080029#include "stats_log_util.h"
Joe Onorato9fc9edf2017-10-15 20:08:52 -070030#include "stats_util.h"
yro947fbce2017-11-15 22:50:23 -080031#include "storage/StorageManager.h"
Joe Onorato9fc9edf2017-10-15 20:08:52 -070032
yro00698da2017-09-15 10:06:40 -070033#include <log/log_event_list.h>
Yao Chenef99c4f2017-09-22 16:26:54 -070034#include <utils/Errors.h>
David Chen16049572018-02-01 18:27:51 -080035#include <utils/SystemClock.h>
Yao Chenab273e22017-09-06 12:53:50 -070036
37using namespace android;
yro947fbce2017-11-15 22:50:23 -080038using android::base::StringPrintf;
yrob0378b02017-11-09 20:36:25 -080039using android::util::FIELD_COUNT_REPEATED;
yro17adac92017-11-08 23:16:29 -080040using android::util::FIELD_TYPE_BOOL;
41using android::util::FIELD_TYPE_FLOAT;
42using android::util::FIELD_TYPE_INT32;
43using android::util::FIELD_TYPE_INT64;
44using android::util::FIELD_TYPE_MESSAGE;
45using android::util::FIELD_TYPE_STRING;
46using android::util::ProtoOutputStream;
Yao Chen44cf27c2017-09-14 22:32:50 -070047using std::make_unique;
48using std::unique_ptr;
49using std::vector;
Bookatz906a35c2017-09-20 15:26:44 -070050
51namespace android {
52namespace os {
53namespace statsd {
Yao Chenab273e22017-09-06 12:53:50 -070054
yro947fbce2017-11-15 22:50:23 -080055// for ConfigMetricsReportList
yro17adac92017-11-08 23:16:29 -080056const int FIELD_ID_CONFIG_KEY = 1;
yro947fbce2017-11-15 22:50:23 -080057const int FIELD_ID_REPORTS = 2;
yro17adac92017-11-08 23:16:29 -080058// for ConfigKey
59const int FIELD_ID_UID = 1;
Yangster-mac94e197c2018-01-02 16:03:03 -080060const int FIELD_ID_ID = 2;
yro947fbce2017-11-15 22:50:23 -080061// for ConfigMetricsReport
Yao Chen4c959cb2018-02-13 13:27:48 -080062// const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp
yro947fbce2017-11-15 22:50:23 -080063const int FIELD_ID_UID_MAP = 2;
Yangster-mac330af582018-02-08 15:24:38 -080064const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3;
65const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4;
Yangster-mac3fa5d7f2018-03-10 21:50:27 -080066const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5;
67const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6;
Chenjie Yue36018b2018-04-16 15:18:30 -070068const int FIELD_ID_DUMP_REPORT_REASON = 8;
Yangster-mac9def8e32018-04-17 13:55:51 -070069const int FIELD_ID_STRINGS = 9;
Yangster-mac3fa5d7f2018-03-10 21:50:27 -080070
Chenjie Yuc7939cb2019-02-04 17:25:45 -080071const int FIELD_ID_ACTIVE_CONFIG_LIST = 1;
72const int FIELD_ID_CONFIG_ID = 1;
73const int FIELD_ID_CONFIG_UID = 2;
74const int FIELD_ID_ACTIVE_METRIC = 3;
75const int FIELD_ID_METRIC_ID = 1;
76const int FIELD_ID_TIME_TO_LIVE_NANOS = 2;
77
Yangster-macb142cc82018-03-30 15:22:08 -070078#define NS_PER_HOUR 3600 * NS_PER_SEC
yro947fbce2017-11-15 22:50:23 -080079
yro03faf092017-12-12 00:17:50 -080080#define STATS_DATA_DIR "/data/misc/stats-data"
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
Yangster-mace2cd6d52017-11-09 20:38:30 -0800109void StatsLogProcessor::onAnomalyAlarmFired(
Yangster-macb142cc82018-03-30 15:22:08 -0700110 const int64_t& timestampNs,
Yangster-mac932ecec2018-02-01 10:23:52 -0800111 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
Yangster-macb0d06282018-01-05 15:44:07 -0800112 std::lock_guard<std::mutex> lock(mMetricsMutex);
Bookatzcc5adef22017-11-21 14:36:23 -0800113 for (const auto& itr : mMetricsManagers) {
Yangster-mac932ecec2018-02-01 10:23:52 -0800114 itr.second->onAnomalyAlarmFired(timestampNs, alarmSet);
115 }
116}
117void StatsLogProcessor::onPeriodicAlarmFired(
Yangster-macb142cc82018-03-30 15:22:08 -0700118 const int64_t& timestampNs,
Yangster-mac932ecec2018-02-01 10:23:52 -0800119 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
120
121 std::lock_guard<std::mutex> lock(mMetricsMutex);
122 for (const auto& itr : mMetricsManagers) {
123 itr.second->onPeriodicAlarmFired(timestampNs, alarmSet);
Yangster-mace2cd6d52017-11-09 20:38:30 -0800124 }
125}
126
Yao Chen8a8d16c2018-02-08 14:50:40 -0800127void updateUid(Value* value, int hostUid) {
128 int uid = value->int_value;
129 if (uid != hostUid) {
130 value->setInt(hostUid);
131 }
132}
133
Yangster-macd40053e2018-01-09 16:29:22 -0800134void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const {
Yao Chenc40a19d2018-03-15 16:48:25 -0700135 if (android::util::AtomsInfo::kAtomsWithAttributionChain.find(event->GetTagId()) !=
136 android::util::AtomsInfo::kAtomsWithAttributionChain.end()) {
Yao Chen8a8d16c2018-02-08 14:50:40 -0800137 for (auto& value : *(event->getMutableValues())) {
138 if (value.mField.getPosAtDepth(0) > kAttributionField) {
139 break;
140 }
141 if (isAttributionUidField(value)) {
142 const int hostUid = mUidMap->getHostUidOrSelf(value.mValue.int_value);
143 updateUid(&value.mValue, hostUid);
144 }
Yangster-macd40053e2018-01-09 16:29:22 -0800145 }
Yao Chenc40a19d2018-03-15 16:48:25 -0700146 } else {
147 auto it = android::util::AtomsInfo::kAtomsWithUidField.find(event->GetTagId());
148 if (it != android::util::AtomsInfo::kAtomsWithUidField.end()) {
149 int uidField = it->second; // uidField is the field number in proto,
150 // starting from 1
151 if (uidField > 0 && (int)event->getValues().size() >= uidField &&
152 (event->getValues())[uidField - 1].mValue.getType() == INT) {
153 Value& value = (*event->getMutableValues())[uidField - 1].mValue;
154 const int hostUid = mUidMap->getHostUidOrSelf(value.int_value);
155 updateUid(&value, hostUid);
156 } else {
157 ALOGE("Malformed log, uid not found. %s", event->ToString().c_str());
158 }
159 }
Yao Chen312e8982017-12-05 15:29:03 -0800160 }
Yangster-macd40053e2018-01-09 16:29:22 -0800161}
162
163void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
164 status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR;
165 bool is_create = event.GetBool(3, &err);
166 auto parent_uid = int(event.GetLong(1, &err2));
167 auto isolated_uid = int(event.GetLong(2, &err3));
168 if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) {
169 if (is_create) {
170 mUidMap->assignIsolatedUid(isolated_uid, parent_uid);
171 } else {
Bookatz3c648862018-05-25 13:32:43 -0700172 mUidMap->removeIsolatedUid(isolated_uid);
Yangster-macd40053e2018-01-09 16:29:22 -0800173 }
174 } else {
175 ALOGE("Failed to parse uid in the isolated uid change event.");
176 }
177}
178
Yangster-mac892f3d32018-05-02 14:16:48 -0700179void StatsLogProcessor::resetConfigs() {
180 std::lock_guard<std::mutex> lock(mMetricsMutex);
181 resetConfigsLocked(getElapsedRealtimeNs());
182}
183
184void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) {
185 std::vector<ConfigKey> configKeys;
186 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
187 configKeys.push_back(it->first);
188 }
189 resetConfigsLocked(timestampNs, configKeys);
190}
191
Yao Chen3ff3a492018-08-06 16:17:37 -0700192void StatsLogProcessor::OnLogEvent(LogEvent* event) {
Yangster-macd40053e2018-01-09 16:29:22 -0800193 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yao Chen876889c2018-05-02 11:16:16 -0700194
195#ifdef VERY_VERBOSE_PRINTING
196 if (mPrintAllLogs) {
197 ALOGI("%s", event->ToString().c_str());
198 }
199#endif
Yangster-macb142cc82018-03-30 15:22:08 -0700200 const int64_t currentTimestampNs = event->GetElapsedTimestampNs();
Yangster-macb8382a12018-04-04 10:39:12 -0700201
Yangster-macb142cc82018-03-30 15:22:08 -0700202 resetIfConfigTtlExpiredLocked(currentTimestampNs);
203
Yangster-macd40053e2018-01-09 16:29:22 -0800204 StatsdStats::getInstance().noteAtomLogged(
Yangster-mac330af582018-02-08 15:24:38 -0800205 event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC);
Yangster-macd40053e2018-01-09 16:29:22 -0800206
David Chen21582962017-11-01 17:32:46 -0700207 // Hard-coded logic to update the isolated uid's in the uid-map.
Stefan Lafonae2df012017-11-14 09:17:21 -0800208 // The field numbers need to be currently updated by hand with atoms.proto
Yangster-macd40053e2018-01-09 16:29:22 -0800209 if (event->GetTagId() == android::util::ISOLATED_UID_CHANGED) {
210 onIsolatedUidChangedEventLocked(*event);
David Chencfc311d2018-01-23 17:55:54 -0800211 }
212
213 if (mMetricsManagers.empty()) {
214 return;
215 }
216
Yangster-macb142cc82018-03-30 15:22:08 -0700217 int64_t curTimeSec = getElapsedRealtimeSec();
Yangster-mac330af582018-02-08 15:24:38 -0800218 if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
Chenjie Yue2219202018-06-08 10:07:51 -0700219 mPullerManager->ClearPullerCacheIfNecessary(curTimeSec * NS_PER_SEC);
Yangster-mac330af582018-02-08 15:24:38 -0800220 mLastPullerCacheClearTimeSec = curTimeSec;
Chenjie Yufa22d652018-02-05 14:37:48 -0800221 }
222
Yangster-macb142cc82018-03-30 15:22:08 -0700223
David Chencfc311d2018-01-23 17:55:54 -0800224 if (event->GetTagId() != android::util::ISOLATED_UID_CHANGED) {
Yangster-macd40053e2018-01-09 16:29:22 -0800225 // Map the isolated uid to host uid if necessary.
226 mapIsolatedUidToHostUidIfNecessaryLocked(event);
227 }
228
Tej Singh6ede28b2019-01-29 17:06:54 -0800229 std::unordered_set<int> uidsWithActiveConfigsChanged;
230 std::unordered_map<int, std::vector<int64_t>> activeConfigsPerUid;
Yangster-macd40053e2018-01-09 16:29:22 -0800231 // pass the event to metrics managers.
232 for (auto& pair : mMetricsManagers) {
Tej Singh6ede28b2019-01-29 17:06:54 -0800233 int uid = pair.first.GetUid();
234 int64_t configId = pair.first.GetId();
235 bool isPrevActive = pair.second->isActive();
Yangster-macd40053e2018-01-09 16:29:22 -0800236 pair.second->onLogEvent(*event);
Tej Singh6ede28b2019-01-29 17:06:54 -0800237 bool isCurActive = pair.second->isActive();
238 // Map all active configs by uid.
239 if (isCurActive) {
240 auto activeConfigs = activeConfigsPerUid.find(uid);
241 if (activeConfigs != activeConfigsPerUid.end()) {
242 activeConfigs->second.push_back(configId);
243 } else {
244 vector<int64_t> newActiveConfigs;
245 newActiveConfigs.push_back(configId);
246 activeConfigsPerUid[uid] = newActiveConfigs;
247 }
248 }
249 // The activation state of this config changed.
250 if (isPrevActive != isCurActive) {
251 VLOG("Active status changed for uid %d", uid);
252 uidsWithActiveConfigsChanged.insert(uid);
253 StatsdStats::getInstance().noteActiveStatusChanged(pair.first, isCurActive);
254 }
Yangster-mac330af582018-02-08 15:24:38 -0800255 flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second));
David Chen21582962017-11-01 17:32:46 -0700256 }
Tej Singh6ede28b2019-01-29 17:06:54 -0800257
258 for (int uid : uidsWithActiveConfigsChanged) {
259 // Send broadcast so that receivers can pull data.
260 auto lastBroadcastTime = mLastActivationBroadcastTimes.find(uid);
261 if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) {
262 if (currentTimestampNs - lastBroadcastTime->second <
263 StatsdStats::kMinActivationBroadcastPeriodNs) {
264 VLOG("StatsD would've sent an activation broadcast but the rate limit stopped us.");
265 return;
266 }
267 }
268 auto activeConfigs = activeConfigsPerUid.find(uid);
269 if (activeConfigs != activeConfigsPerUid.end()) {
270 if (mSendActivationBroadcast(uid, activeConfigs->second)) {
271 VLOG("StatsD sent activation notice for uid %d", uid);
272 mLastActivationBroadcastTimes[uid] = currentTimestampNs;
273 }
274 } else {
275 std::vector<int64_t> emptyActiveConfigs;
276 if (mSendActivationBroadcast(uid, emptyActiveConfigs)) {
277 VLOG("StatsD sent EMPTY activation notice for uid %d", uid);
278 mLastActivationBroadcastTimes[uid] = currentTimestampNs;
279 }
280 }
281 }
282}
283
284void StatsLogProcessor::GetActiveConfigs(const int uid, vector<int64_t>& outActiveConfigs) {
285 std::lock_guard<std::mutex> lock(mMetricsMutex);
286 GetActiveConfigsLocked(uid, outActiveConfigs);
287}
288
289void StatsLogProcessor::GetActiveConfigsLocked(const int uid, vector<int64_t>& outActiveConfigs) {
290 outActiveConfigs.clear();
291 for (auto& pair : mMetricsManagers) {
292 if (pair.first.GetUid() == uid && pair.second->isActive()) {
293 outActiveConfigs.push_back(pair.first.GetId());
294 }
295 }
Yao Chenab273e22017-09-06 12:53:50 -0700296}
297
Yangster-macc04feba2018-04-02 14:37:33 -0700298void StatsLogProcessor::OnConfigUpdated(const int64_t timestampNs, const ConfigKey& key,
299 const StatsdConfig& config) {
Yangster-macb0d06282018-01-05 15:44:07 -0800300 std::lock_guard<std::mutex> lock(mMetricsMutex);
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000301 WriteDataToDiskLocked(key, timestampNs, CONFIG_UPDATED, NO_TIME_CONSTRAINTS);
Yangster-macb142cc82018-03-30 15:22:08 -0700302 OnConfigUpdatedLocked(timestampNs, key, config);
303}
304
305void StatsLogProcessor::OnConfigUpdatedLocked(
306 const int64_t timestampNs, const ConfigKey& key, const StatsdConfig& config) {
Tej Singh484524a2018-02-01 15:10:05 -0800307 VLOG("Updated configuration for key %s", key.ToString().c_str());
Yangster-mac932ecec2018-02-01 10:23:52 -0800308 sp<MetricsManager> newMetricsManager =
Chenjie Yue2219202018-06-08 10:07:51 -0700309 new MetricsManager(key, config, mTimeBaseNs, timestampNs, mUidMap, mPullerManager,
310 mAnomalyAlarmMonitor, mPeriodicAlarmMonitor);
Yao Chencaf339d2017-10-06 16:01:10 -0700311 if (newMetricsManager->isConfigValid()) {
David Chend6896892017-10-25 11:49:03 -0700312 mUidMap->OnConfigUpdated(key);
Yao Chen147ce602017-12-22 14:35:34 -0800313 if (newMetricsManager->shouldAddUidMapListener()) {
Yao Chend10f7b12017-12-18 12:53:50 -0800314 // We have to add listener after the MetricsManager is constructed because it's
315 // not safe to create wp or sp from this pointer inside its constructor.
316 mUidMap->addListener(newMetricsManager.get());
317 }
Yangster-macb142cc82018-03-30 15:22:08 -0700318 newMetricsManager->refreshTtl(timestampNs);
Yao Chend10f7b12017-12-18 12:53:50 -0800319 mMetricsManagers[key] = newMetricsManager;
Yao Chenb3561512017-11-21 18:07:17 -0800320 VLOG("StatsdConfig valid");
Yao Chencaf339d2017-10-06 16:01:10 -0700321 } else {
322 // If there is any error in the config, don't use it.
Yao Chenb3561512017-11-21 18:07:17 -0800323 ALOGE("StatsdConfig NOT valid");
Yao Chencaf339d2017-10-06 16:01:10 -0700324 }
yro00698da2017-09-15 10:06:40 -0700325}
Bookatz906a35c2017-09-20 15:26:44 -0700326
Yangster7c334a12017-11-22 14:24:24 -0800327size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const {
Yangster-macb0d06282018-01-05 15:44:07 -0800328 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yao Chen729093d2017-10-16 10:33:26 -0700329 auto it = mMetricsManagers.find(key);
330 if (it == mMetricsManagers.end()) {
331 ALOGW("Config source %s does not exist", key.ToString().c_str());
David Chen1d7b0cd2017-11-15 14:20:04 -0800332 return 0;
Yao Chen729093d2017-10-16 10:33:26 -0700333 }
David Chen1d7b0cd2017-11-15 14:20:04 -0800334 return it->second->byteSize();
335}
336
Yao Chena80e5c02018-09-04 13:55:29 -0700337void StatsLogProcessor::dumpStates(int out, bool verbose) {
Yao Chen884c8c12018-01-26 10:36:25 -0800338 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yao Chena80e5c02018-09-04 13:55:29 -0700339 FILE* fout = fdopen(out, "w");
340 if (fout == NULL) {
341 return;
Yao Chen884c8c12018-01-26 10:36:25 -0800342 }
Yao Chena80e5c02018-09-04 13:55:29 -0700343 fprintf(fout, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size());
344 for (auto metricsManager : mMetricsManagers) {
345 metricsManager.second->dumpStates(fout, verbose);
346 }
347
348 fclose(fout);
Yao Chen884c8c12018-01-26 10:36:25 -0800349}
350
yro4beccbe2018-03-15 19:42:05 -0700351/*
Bookatz9cc7b662018-11-06 10:39:21 -0800352 * onDumpReport dumps serialized ConfigMetricsReportList into proto.
yro4beccbe2018-03-15 19:42:05 -0700353 */
Yangster-macb142cc82018-03-30 15:22:08 -0700354void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
Yangster-mace68f3a52018-04-04 00:01:43 -0700355 const bool include_current_partial_bucket,
Bookatzff71cad2018-09-20 17:17:49 -0700356 const bool erase_data,
Chenjie Yue36018b2018-04-16 15:18:30 -0700357 const DumpReportReason dumpReportReason,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000358 const DumpLatency dumpLatency,
Bookatzff71cad2018-09-20 17:17:49 -0700359 ProtoOutputStream* proto) {
Yangster-macb0d06282018-01-05 15:44:07 -0800360 std::lock_guard<std::mutex> lock(mMetricsMutex);
Yangster-mac20877162017-12-22 17:19:39 -0800361
yro947fbce2017-11-15 22:50:23 -0800362 // Start of ConfigKey.
Bookatzff71cad2018-09-20 17:17:49 -0700363 uint64_t configKeyToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY);
364 proto->write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid());
365 proto->write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId());
366 proto->end(configKeyToken);
yro947fbce2017-11-15 22:50:23 -0800367 // End of ConfigKey.
yro17adac92017-11-08 23:16:29 -0800368
yro947fbce2017-11-15 22:50:23 -0800369 // Then, check stats-data directory to see there's any file containing
370 // ConfigMetricsReport from previous shutdowns to concatenate to reports.
Bookatzc71d9012018-12-19 12:28:38 -0800371 StorageManager::appendConfigMetricsReport(key, proto, erase_data);
yro947fbce2017-11-15 22:50:23 -0800372
Yangster-mace68f3a52018-04-04 00:01:43 -0700373 auto it = mMetricsManagers.find(key);
374 if (it != mMetricsManagers.end()) {
375 // This allows another broadcast to be sent within the rate-limit period if we get close to
376 // filling the buffer again soon.
377 mLastBroadcastTimes.erase(key);
378
379 // Start of ConfigMetricsReport (reports).
380 uint64_t reportsToken =
Bookatzff71cad2018-09-20 17:17:49 -0700381 proto->start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS);
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000382 onConfigMetricsReportLocked(key, dumpTimeStampNs,
383 include_current_partial_bucket,
384 erase_data, dumpReportReason,
385 dumpLatency, proto);
Bookatzff71cad2018-09-20 17:17:49 -0700386 proto->end(reportsToken);
Yangster-mace68f3a52018-04-04 00:01:43 -0700387 // End of ConfigMetricsReport (reports).
388 } else {
389 ALOGW("Config source %s does not exist", key.ToString().c_str());
390 }
Bookatzff71cad2018-09-20 17:17:49 -0700391}
392
393/*
394 * onDumpReport dumps serialized ConfigMetricsReportList into outData.
395 */
396void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
397 const bool include_current_partial_bucket,
398 const bool erase_data,
399 const DumpReportReason dumpReportReason,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000400 const DumpLatency dumpLatency,
Bookatzff71cad2018-09-20 17:17:49 -0700401 vector<uint8_t>* outData) {
402 ProtoOutputStream proto;
403 onDumpReport(key, dumpTimeStampNs, include_current_partial_bucket, erase_data,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000404 dumpReportReason, dumpLatency, &proto);
Yangster-mace68f3a52018-04-04 00:01:43 -0700405
David Chen1d7b0cd2017-11-15 14:20:04 -0800406 if (outData != nullptr) {
407 outData->clear();
408 outData->resize(proto.size());
409 size_t pos = 0;
Joe Onorato99598ee2019-02-11 15:55:13 +0000410 sp<android::util::ProtoReader> reader = proto.data();
411 while (reader->readBuffer() != NULL) {
412 size_t toRead = reader->currentToRead();
413 std::memcpy(&((*outData)[pos]), reader->readBuffer(), toRead);
David Chen1d7b0cd2017-11-15 14:20:04 -0800414 pos += toRead;
Joe Onorato99598ee2019-02-11 15:55:13 +0000415 reader->move(toRead);
David Chen1d7b0cd2017-11-15 14:20:04 -0800416 }
yro17adac92017-11-08 23:16:29 -0800417 }
Yao Chen8a8d16c2018-02-08 14:50:40 -0800418
Yangster-mace68f3a52018-04-04 00:01:43 -0700419 StatsdStats::getInstance().noteMetricsReportSent(key, proto.size());
Yao Chen729093d2017-10-16 10:33:26 -0700420}
421
yro4beccbe2018-03-15 19:42:05 -0700422/*
423 * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData.
424 */
425void StatsLogProcessor::onConfigMetricsReportLocked(const ConfigKey& key,
Yangster-macb142cc82018-03-30 15:22:08 -0700426 const int64_t dumpTimeStampNs,
Yangster-mace68f3a52018-04-04 00:01:43 -0700427 const bool include_current_partial_bucket,
Bookatzff71cad2018-09-20 17:17:49 -0700428 const bool erase_data,
Chenjie Yue36018b2018-04-16 15:18:30 -0700429 const DumpReportReason dumpReportReason,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000430 const DumpLatency dumpLatency,
yro4beccbe2018-03-15 19:42:05 -0700431 ProtoOutputStream* proto) {
432 // We already checked whether key exists in mMetricsManagers in
433 // WriteDataToDisk.
434 auto it = mMetricsManagers.find(key);
Yangster-mace68f3a52018-04-04 00:01:43 -0700435 if (it == mMetricsManagers.end()) {
436 return;
437 }
yro4beccbe2018-03-15 19:42:05 -0700438 int64_t lastReportTimeNs = it->second->getLastReportTimeNs();
439 int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs();
440
Yangster-mac9def8e32018-04-17 13:55:51 -0700441 std::set<string> str_set;
442
yro4beccbe2018-03-15 19:42:05 -0700443 // First, fill in ConfigMetricsReport using current data on memory, which
444 // starts from filling in StatsLogReport's.
Yangster-mac9def8e32018-04-17 13:55:51 -0700445 it->second->onDumpReport(dumpTimeStampNs, include_current_partial_bucket,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000446 erase_data, dumpLatency, &str_set, proto);
yro4beccbe2018-03-15 19:42:05 -0700447
David Chen9e6dbbd2018-05-07 17:52:29 -0700448 // Fill in UidMap if there is at least one metric to report.
449 // This skips the uid map if it's an empty config.
450 if (it->second->getNumMetrics() > 0) {
451 uint64_t uidMapToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP);
dwchen730403e2018-10-29 11:41:56 -0700452 mUidMap->appendUidMap(
453 dumpTimeStampNs, key, it->second->hashStringInReport() ? &str_set : nullptr,
454 it->second->versionStringsInReport(), it->second->installerInReport(), proto);
David Chen9e6dbbd2018-05-07 17:52:29 -0700455 proto->end(uidMapToken);
456 }
yro4beccbe2018-03-15 19:42:05 -0700457
458 // Fill in the timestamps.
459 proto->write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS,
460 (long long)lastReportTimeNs);
461 proto->write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS,
462 (long long)dumpTimeStampNs);
463 proto->write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS,
464 (long long)lastReportWallClockNs);
465 proto->write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS,
466 (long long)getWallClockNs());
Chenjie Yue36018b2018-04-16 15:18:30 -0700467 // Dump report reason
468 proto->write(FIELD_TYPE_INT32 | FIELD_ID_DUMP_REPORT_REASON, dumpReportReason);
Yangster-mac9def8e32018-04-17 13:55:51 -0700469
David Chen56ae0d92018-05-11 16:00:22 -0700470 for (const auto& str : str_set) {
471 proto->write(FIELD_TYPE_STRING | FIELD_COUNT_REPEATED | FIELD_ID_STRINGS, str);
Yangster-mac9def8e32018-04-17 13:55:51 -0700472 }
Yangster-macb142cc82018-03-30 15:22:08 -0700473}
yro4beccbe2018-03-15 19:42:05 -0700474
Yao Chen163d2602018-04-10 10:39:53 -0700475void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs,
476 const std::vector<ConfigKey>& configs) {
477 for (const auto& key : configs) {
Yangster-macb142cc82018-03-30 15:22:08 -0700478 StatsdConfig config;
479 if (StorageManager::readConfigFromDisk(key, &config)) {
480 OnConfigUpdatedLocked(timestampNs, key, config);
481 StatsdStats::getInstance().noteConfigReset(key);
482 } else {
483 ALOGE("Failed to read backup config from disk for : %s", key.ToString().c_str());
484 auto it = mMetricsManagers.find(key);
485 if (it != mMetricsManagers.end()) {
486 it->second->refreshTtl(timestampNs);
487 }
488 }
489 }
yro4beccbe2018-03-15 19:42:05 -0700490}
491
Yao Chen163d2602018-04-10 10:39:53 -0700492void StatsLogProcessor::resetIfConfigTtlExpiredLocked(const int64_t timestampNs) {
493 std::vector<ConfigKey> configKeysTtlExpired;
494 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
495 if (it->second != nullptr && !it->second->isInTtl(timestampNs)) {
496 configKeysTtlExpired.push_back(it->first);
497 }
498 }
499 if (configKeysTtlExpired.size() > 0) {
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000500 WriteDataToDiskLocked(CONFIG_RESET, NO_TIME_CONSTRAINTS);
Yao Chen163d2602018-04-10 10:39:53 -0700501 resetConfigsLocked(timestampNs, configKeysTtlExpired);
502 }
503}
504
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700505void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
Yangster-macb0d06282018-01-05 15:44:07 -0800506 std::lock_guard<std::mutex> lock(mMetricsMutex);
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700507 auto it = mMetricsManagers.find(key);
508 if (it != mMetricsManagers.end()) {
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000509 WriteDataToDiskLocked(key, getElapsedRealtimeNs(), CONFIG_REMOVED,
510 NO_TIME_CONSTRAINTS);
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700511 mMetricsManagers.erase(it);
David Chend6896892017-10-25 11:49:03 -0700512 mUidMap->OnConfigRemoved(key);
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700513 }
Yao Chenb3561512017-11-21 18:07:17 -0800514 StatsdStats::getInstance().noteConfigRemoved(key);
David Chen1d7b0cd2017-11-15 14:20:04 -0800515
David Chen1d7b0cd2017-11-15 14:20:04 -0800516 mLastBroadcastTimes.erase(key);
Chenjie Yufa22d652018-02-05 14:37:48 -0800517
Tej Singh6ede28b2019-01-29 17:06:54 -0800518 int uid = key.GetUid();
519 bool lastConfigForUid = true;
520 for (auto it : mMetricsManagers) {
521 if (it.first.GetUid() == uid) {
522 lastConfigForUid = false;
523 break;
524 }
525 }
526 if (lastConfigForUid) {
527 mLastActivationBroadcastTimes.erase(uid);
528 }
529
Chenjie Yufa22d652018-02-05 14:37:48 -0800530 if (mMetricsManagers.empty()) {
Chenjie Yue2219202018-06-08 10:07:51 -0700531 mPullerManager->ForceClearPullerCache();
Chenjie Yufa22d652018-02-05 14:37:48 -0800532 }
Joe Onorato9fc9edf2017-10-15 20:08:52 -0700533}
534
Yangster-macb0d06282018-01-05 15:44:07 -0800535void StatsLogProcessor::flushIfNecessaryLocked(
Yangster-macb142cc82018-03-30 15:22:08 -0700536 int64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) {
David Chend9269e22017-12-05 13:43:51 -0800537 auto lastCheckTime = mLastByteSizeTimes.find(key);
538 if (lastCheckTime != mLastByteSizeTimes.end()) {
539 if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
540 return;
541 }
542 }
543
544 // We suspect that the byteSize() computation is expensive, so we set a rate limit.
545 size_t totalBytes = metricsManager.byteSize();
546 mLastByteSizeTimes[key] = timestampNs;
David Chen48944902018-05-03 10:29:11 -0700547 bool requestDump = false;
David Chend9269e22017-12-05 13:43:51 -0800548 if (totalBytes >
549 StatsdStats::kMaxMetricsBytesPerConfig) { // Too late. We need to start clearing data.
Yao Chen06dba5d2018-01-26 13:38:16 -0800550 metricsManager.dropData(timestampNs);
Chenjie Yuc3c30c02018-10-26 09:48:07 -0700551 StatsdStats::getInstance().noteDataDropped(key, totalBytes);
David Chen12942952017-12-04 14:28:43 -0800552 VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
David Chen48944902018-05-03 10:29:11 -0700553 } else if ((totalBytes > StatsdStats::kBytesPerConfigTriggerGetData) ||
554 (mOnDiskDataConfigs.find(key) != mOnDiskDataConfigs.end())) {
555 // Request to send a broadcast if:
556 // 1. in memory data > threshold OR
557 // 2. config has old data report on disk.
558 requestDump = true;
559 }
560
561 if (requestDump) {
David Chend9269e22017-12-05 13:43:51 -0800562 // Send broadcast so that receivers can pull data.
563 auto lastBroadcastTime = mLastBroadcastTimes.find(key);
564 if (lastBroadcastTime != mLastBroadcastTimes.end()) {
565 if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) {
566 VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
David Chen1d7b0cd2017-11-15 14:20:04 -0800567 return;
568 }
569 }
David Chen48944902018-05-03 10:29:11 -0700570 if (mSendBroadcast(key)) {
571 mOnDiskDataConfigs.erase(key);
572 VLOG("StatsD triggered data fetch for %s", key.ToString().c_str());
573 mLastBroadcastTimes[key] = timestampNs;
574 StatsdStats::getInstance().noteBroadcastSent(key);
575 }
yro31eb67b2017-10-24 13:33:21 -0700576 }
577}
578
Chenjie Yue36018b2018-04-16 15:18:30 -0700579void StatsLogProcessor::WriteDataToDiskLocked(const ConfigKey& key,
Yangster-mac892f3d32018-05-02 14:16:48 -0700580 const int64_t timestampNs,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000581 const DumpReportReason dumpReportReason,
582 const DumpLatency dumpLatency) {
yro028091c2018-05-09 16:03:27 -0700583 if (mMetricsManagers.find(key) == mMetricsManagers.end() ||
584 !mMetricsManagers.find(key)->second->shouldWriteToDisk()) {
Yangster-mac892f3d32018-05-02 14:16:48 -0700585 return;
586 }
Yangster-mace68f3a52018-04-04 00:01:43 -0700587 ProtoOutputStream proto;
David Chen56ae0d92018-05-11 16:00:22 -0700588 onConfigMetricsReportLocked(key, timestampNs, true /* include_current_partial_bucket*/,
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000589 true /* erase_data */, dumpReportReason, dumpLatency, &proto);
Yangster-mace68f3a52018-04-04 00:01:43 -0700590 string file_name = StringPrintf("%s/%ld_%d_%lld", STATS_DATA_DIR,
591 (long)getWallClockSec(), key.GetUid(), (long long)key.GetId());
592 android::base::unique_fd fd(open(file_name.c_str(),
593 O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR));
594 if (fd == -1) {
595 ALOGE("Attempt to write %s but failed", file_name.c_str());
596 return;
597 }
598 proto.flush(fd.get());
David Chen48944902018-05-03 10:29:11 -0700599 // We were able to write the ConfigMetricsReport to disk, so we should trigger collection ASAP.
600 mOnDiskDataConfigs.insert(key);
Yangster-mace68f3a52018-04-04 00:01:43 -0700601}
602
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800603void StatsLogProcessor::WriteMetricsActivationToDisk(int64_t currentTimeNs) {
604 std::lock_guard<std::mutex> lock(mMetricsMutex);
605 ProtoOutputStream proto;
606
607 for (const auto& pair : mMetricsManagers) {
608 uint64_t activeConfigListToken = proto.start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED |
609 FIELD_ID_ACTIVE_CONFIG_LIST);
610 proto.write(FIELD_TYPE_INT64 | FIELD_ID_CONFIG_ID, (long long)pair.first.GetId());
611 proto.write(FIELD_TYPE_INT32 | FIELD_ID_CONFIG_UID, pair.first.GetUid());
612
Chenjie Yua9a310e2019-02-06 13:40:10 -0800613 vector<MetricProducer*> activeMetrics;
614 pair.second->prepForShutDown(currentTimeNs);
615 pair.second->getActiveMetrics(activeMetrics);
616 for (MetricProducer* metric : activeMetrics) {
Chenjie Yuc7939cb2019-02-04 17:25:45 -0800617 if (metric->isActive()) {
618 uint64_t metricToken = proto.start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED |
619 FIELD_ID_ACTIVE_METRIC);
620 proto.write(FIELD_TYPE_INT64 | FIELD_ID_METRIC_ID,
621 (long long)metric->getMetricId());
622 proto.write(FIELD_TYPE_INT64 | FIELD_ID_TIME_TO_LIVE_NANOS,
623 (long long)metric->getRemainingTtlNs(currentTimeNs));
624 proto.end(metricToken);
625 }
626 }
627 proto.end(activeConfigListToken);
628 }
629
630 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
631 StorageManager::deleteFile(file_name.c_str());
632 android::base::unique_fd fd(
633 open(file_name.c_str(), O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR));
634 if (fd == -1) {
635 ALOGE("Attempt to write %s but failed", file_name.c_str());
636 return;
637 }
638 proto.flush(fd.get());
639}
640
641void StatsLogProcessor::LoadMetricsActivationFromDisk() {
642 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
643 int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC);
644 if (fd != -1) {
645 string content;
646 if (android::base::ReadFdToString(fd, &content)) {
647 ActiveConfigList activeConfigList;
648 if (activeConfigList.ParseFromString(content)) {
649 for (int i = 0; i < activeConfigList.active_config_size(); i++) {
650 const auto& config = activeConfigList.active_config(i);
651 ConfigKey key(config.uid(), config.config_id());
652 auto it = mMetricsManagers.find(key);
653 if (it == mMetricsManagers.end()) {
654 ALOGE("No config found for config %s", key.ToString().c_str());
655 continue;
656 }
657 VLOG("Setting active config %s", key.ToString().c_str());
658 it->second->setActiveMetrics(config, mTimeBaseNs);
659 }
660 }
661 VLOG("Successfully loaded %d active configs.", activeConfigList.active_config_size());
662 }
663 close(fd);
664 }
665 StorageManager::deleteFile(file_name.c_str());
666}
667
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000668void StatsLogProcessor::WriteDataToDiskLocked(const DumpReportReason dumpReportReason,
669 const DumpLatency dumpLatency) {
Yangster-mac892f3d32018-05-02 14:16:48 -0700670 const int64_t timeNs = getElapsedRealtimeNs();
Tej Singh42f9e062018-11-09 10:01:00 -0800671 // Do not write to disk if we already have in the last few seconds.
672 // This is to avoid overwriting files that would have the same name if we
673 // write twice in the same second.
674 if (static_cast<unsigned long long> (timeNs) <
675 mLastWriteTimeNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
676 ALOGI("Statsd skipping writing data to disk. Already wrote data in last %d seconds",
677 WRITE_DATA_COOL_DOWN_SEC);
678 return;
679 }
680 mLastWriteTimeNs = timeNs;
Yangster-mace68f3a52018-04-04 00:01:43 -0700681 for (auto& pair : mMetricsManagers) {
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000682 WriteDataToDiskLocked(pair.first, timeNs, dumpReportReason, dumpLatency);
Yangster-mace68f3a52018-04-04 00:01:43 -0700683 }
684}
685
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000686void StatsLogProcessor::WriteDataToDisk(const DumpReportReason dumpReportReason,
687 const DumpLatency dumpLatency) {
Yangster-macb0d06282018-01-05 15:44:07 -0800688 std::lock_guard<std::mutex> lock(mMetricsMutex);
Olivier Gaillard6c75ecd2019-02-20 09:57:33 +0000689 WriteDataToDiskLocked(dumpReportReason, dumpLatency);
yro947fbce2017-11-15 22:50:23 -0800690}
691
Yangster-mac15f6bbc2018-04-08 11:52:26 -0700692void StatsLogProcessor::informPullAlarmFired(const int64_t timestampNs) {
Yangster6df5fcc2018-04-12 11:04:29 -0700693 std::lock_guard<std::mutex> lock(mMetricsMutex);
Chenjie Yue2219202018-06-08 10:07:51 -0700694 mPullerManager->OnAlarmFired(timestampNs);
Yangster-mac15f6bbc2018-04-08 11:52:26 -0700695}
696
David Chend37bc232018-04-12 18:05:11 -0700697int64_t StatsLogProcessor::getLastReportTimeNs(const ConfigKey& key) {
698 auto it = mMetricsManagers.find(key);
699 if (it == mMetricsManagers.end()) {
700 return 0;
701 } else {
702 return it->second->getLastReportTimeNs();
703 }
704}
705
David Chen48944902018-05-03 10:29:11 -0700706void StatsLogProcessor::noteOnDiskData(const ConfigKey& key) {
707 std::lock_guard<std::mutex> lock(mMetricsMutex);
708 mOnDiskDataConfigs.insert(key);
709}
710
Yao Chenef99c4f2017-09-22 16:26:54 -0700711} // namespace statsd
712} // namespace os
713} // namespace android