1 /*
2 * Copyright (C) 2017 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #define DEBUG false // STOPSHIP if true
18 #include "Log.h"
19
20 #include "StatsLogProcessor.h"
21
22 #include <android-base/file.h>
23 #include <frameworks/base/cmds/statsd/src/active_config_list.pb.h>
24
25 #include "android-base/stringprintf.h"
26 #include "atoms_info.h"
27 #include "external/StatsPullerManager.h"
28 #include "guardrail/StatsdStats.h"
29 #include "metrics/CountMetricProducer.h"
30 #include "stats_log_util.h"
31 #include "stats_util.h"
32 #include "statslog.h"
33 #include "storage/StorageManager.h"
34
35 using namespace android;
36 using android::base::StringPrintf;
37 using android::util::FIELD_COUNT_REPEATED;
38 using android::util::FIELD_TYPE_BOOL;
39 using android::util::FIELD_TYPE_FLOAT;
40 using android::util::FIELD_TYPE_INT32;
41 using android::util::FIELD_TYPE_INT64;
42 using android::util::FIELD_TYPE_MESSAGE;
43 using android::util::FIELD_TYPE_STRING;
44 using android::util::ProtoOutputStream;
45 using std::vector;
46
47 namespace android {
48 namespace os {
49 namespace statsd {
50
51 // for ConfigMetricsReportList
52 const int FIELD_ID_CONFIG_KEY = 1;
53 const int FIELD_ID_REPORTS = 2;
54 // for ConfigKey
55 const int FIELD_ID_UID = 1;
56 const int FIELD_ID_ID = 2;
57 // for ConfigMetricsReport
58 // const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp
59 const int FIELD_ID_UID_MAP = 2;
60 const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3;
61 const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4;
62 const int FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS = 5;
63 const int FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS = 6;
64 const int FIELD_ID_DUMP_REPORT_REASON = 8;
65 const int FIELD_ID_STRINGS = 9;
66
67 // for ActiveConfigList
68 const int FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG = 1;
69
70 #define NS_PER_HOUR 3600 * NS_PER_SEC
71
72 #define STATS_ACTIVE_METRIC_DIR "/data/misc/stats-active-metric"
73
74 // Cool down period for writing data to disk to avoid overwriting files.
75 #define WRITE_DATA_COOL_DOWN_SEC 5
76
StatsLogProcessor(const sp<UidMap> & uidMap,const sp<StatsPullerManager> & pullerManager,const sp<AlarmMonitor> & anomalyAlarmMonitor,const sp<AlarmMonitor> & periodicAlarmMonitor,const int64_t timeBaseNs,const std::function<bool (const ConfigKey &)> & sendBroadcast,const std::function<bool (const int &,const vector<int64_t> &)> & activateBroadcast)77 StatsLogProcessor::StatsLogProcessor(const sp<UidMap>& uidMap,
78 const sp<StatsPullerManager>& pullerManager,
79 const sp<AlarmMonitor>& anomalyAlarmMonitor,
80 const sp<AlarmMonitor>& periodicAlarmMonitor,
81 const int64_t timeBaseNs,
82 const std::function<bool(const ConfigKey&)>& sendBroadcast,
83 const std::function<bool(
84 const int&, const vector<int64_t>&)>& activateBroadcast)
85 : mUidMap(uidMap),
86 mPullerManager(pullerManager),
87 mAnomalyAlarmMonitor(anomalyAlarmMonitor),
88 mPeriodicAlarmMonitor(periodicAlarmMonitor),
89 mSendBroadcast(sendBroadcast),
90 mSendActivationBroadcast(activateBroadcast),
91 mTimeBaseNs(timeBaseNs),
92 mLargestTimestampSeen(0),
93 mLastTimestampSeen(0) {
94 mPullerManager->ForceClearPullerCache();
95 }
96
~StatsLogProcessor()97 StatsLogProcessor::~StatsLogProcessor() {
98 }
99
flushProtoToBuffer(ProtoOutputStream & proto,vector<uint8_t> * outData)100 static void flushProtoToBuffer(ProtoOutputStream& proto, vector<uint8_t>* outData) {
101 outData->clear();
102 outData->resize(proto.size());
103 size_t pos = 0;
104 sp<android::util::ProtoReader> reader = proto.data();
105 while (reader->readBuffer() != NULL) {
106 size_t toRead = reader->currentToRead();
107 std::memcpy(&((*outData)[pos]), reader->readBuffer(), toRead);
108 pos += toRead;
109 reader->move(toRead);
110 }
111 }
112
onAnomalyAlarmFired(const int64_t & timestampNs,unordered_set<sp<const InternalAlarm>,SpHash<InternalAlarm>> alarmSet)113 void StatsLogProcessor::onAnomalyAlarmFired(
114 const int64_t& timestampNs,
115 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
116 std::lock_guard<std::mutex> lock(mMetricsMutex);
117 for (const auto& itr : mMetricsManagers) {
118 itr.second->onAnomalyAlarmFired(timestampNs, alarmSet);
119 }
120 }
onPeriodicAlarmFired(const int64_t & timestampNs,unordered_set<sp<const InternalAlarm>,SpHash<InternalAlarm>> alarmSet)121 void StatsLogProcessor::onPeriodicAlarmFired(
122 const int64_t& timestampNs,
123 unordered_set<sp<const InternalAlarm>, SpHash<InternalAlarm>> alarmSet) {
124
125 std::lock_guard<std::mutex> lock(mMetricsMutex);
126 for (const auto& itr : mMetricsManagers) {
127 itr.second->onPeriodicAlarmFired(timestampNs, alarmSet);
128 }
129 }
130
updateUid(Value * value,int hostUid)131 void updateUid(Value* value, int hostUid) {
132 int uid = value->int_value;
133 if (uid != hostUid) {
134 value->setInt(hostUid);
135 }
136 }
137
mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent * event) const138 void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const {
139 if (android::util::AtomsInfo::kAtomsWithAttributionChain.find(event->GetTagId()) !=
140 android::util::AtomsInfo::kAtomsWithAttributionChain.end()) {
141 for (auto& value : *(event->getMutableValues())) {
142 if (value.mField.getPosAtDepth(0) > kAttributionField) {
143 break;
144 }
145 if (isAttributionUidField(value)) {
146 const int hostUid = mUidMap->getHostUidOrSelf(value.mValue.int_value);
147 updateUid(&value.mValue, hostUid);
148 }
149 }
150 } else {
151 auto it = android::util::AtomsInfo::kAtomsWithUidField.find(event->GetTagId());
152 if (it != android::util::AtomsInfo::kAtomsWithUidField.end()) {
153 int uidField = it->second; // uidField is the field number in proto,
154 // starting from 1
155 if (uidField > 0 && (int)event->getValues().size() >= uidField &&
156 (event->getValues())[uidField - 1].mValue.getType() == INT) {
157 Value& value = (*event->getMutableValues())[uidField - 1].mValue;
158 const int hostUid = mUidMap->getHostUidOrSelf(value.int_value);
159 updateUid(&value, hostUid);
160 } else {
161 ALOGE("Malformed log, uid not found. %s", event->ToString().c_str());
162 }
163 }
164 }
165 }
166
onIsolatedUidChangedEventLocked(const LogEvent & event)167 void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
168 status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR;
169 bool is_create = event.GetBool(3, &err);
170 auto parent_uid = int(event.GetLong(1, &err2));
171 auto isolated_uid = int(event.GetLong(2, &err3));
172 if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) {
173 if (is_create) {
174 mUidMap->assignIsolatedUid(isolated_uid, parent_uid);
175 } else {
176 mUidMap->removeIsolatedUid(isolated_uid);
177 }
178 } else {
179 ALOGE("Failed to parse uid in the isolated uid change event.");
180 }
181 }
182
resetConfigs()183 void StatsLogProcessor::resetConfigs() {
184 std::lock_guard<std::mutex> lock(mMetricsMutex);
185 resetConfigsLocked(getElapsedRealtimeNs());
186 }
187
resetConfigsLocked(const int64_t timestampNs)188 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs) {
189 std::vector<ConfigKey> configKeys;
190 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
191 configKeys.push_back(it->first);
192 }
193 resetConfigsLocked(timestampNs, configKeys);
194 }
195
OnLogEvent(LogEvent * event)196 void StatsLogProcessor::OnLogEvent(LogEvent* event) {
197 std::lock_guard<std::mutex> lock(mMetricsMutex);
198
199 #ifdef VERY_VERBOSE_PRINTING
200 if (mPrintAllLogs) {
201 ALOGI("%s", event->ToString().c_str());
202 }
203 #endif
204 const int64_t currentTimestampNs = event->GetElapsedTimestampNs();
205
206 resetIfConfigTtlExpiredLocked(currentTimestampNs);
207
208 StatsdStats::getInstance().noteAtomLogged(
209 event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC);
210
211 // Hard-coded logic to update the isolated uid's in the uid-map.
212 // The field numbers need to be currently updated by hand with atoms.proto
213 if (event->GetTagId() == android::util::ISOLATED_UID_CHANGED) {
214 onIsolatedUidChangedEventLocked(*event);
215 }
216
217 if (mMetricsManagers.empty()) {
218 return;
219 }
220
221 int64_t curTimeSec = getElapsedRealtimeSec();
222 if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
223 mPullerManager->ClearPullerCacheIfNecessary(curTimeSec * NS_PER_SEC);
224 mLastPullerCacheClearTimeSec = curTimeSec;
225 }
226
227
228 if (event->GetTagId() != android::util::ISOLATED_UID_CHANGED) {
229 // Map the isolated uid to host uid if necessary.
230 mapIsolatedUidToHostUidIfNecessaryLocked(event);
231 }
232
233 std::unordered_set<int> uidsWithActiveConfigsChanged;
234 std::unordered_map<int, std::vector<int64_t>> activeConfigsPerUid;
235 // pass the event to metrics managers.
236 for (auto& pair : mMetricsManagers) {
237 int uid = pair.first.GetUid();
238 int64_t configId = pair.first.GetId();
239 bool isPrevActive = pair.second->isActive();
240 pair.second->onLogEvent(*event);
241 bool isCurActive = pair.second->isActive();
242 // Map all active configs by uid.
243 if (isCurActive) {
244 auto activeConfigs = activeConfigsPerUid.find(uid);
245 if (activeConfigs != activeConfigsPerUid.end()) {
246 activeConfigs->second.push_back(configId);
247 } else {
248 vector<int64_t> newActiveConfigs;
249 newActiveConfigs.push_back(configId);
250 activeConfigsPerUid[uid] = newActiveConfigs;
251 }
252 }
253 // The activation state of this config changed.
254 if (isPrevActive != isCurActive) {
255 VLOG("Active status changed for uid %d", uid);
256 uidsWithActiveConfigsChanged.insert(uid);
257 StatsdStats::getInstance().noteActiveStatusChanged(pair.first, isCurActive);
258 }
259 flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second));
260 }
261
262 for (int uid : uidsWithActiveConfigsChanged) {
263 // Send broadcast so that receivers can pull data.
264 auto lastBroadcastTime = mLastActivationBroadcastTimes.find(uid);
265 if (lastBroadcastTime != mLastActivationBroadcastTimes.end()) {
266 if (currentTimestampNs - lastBroadcastTime->second <
267 StatsdStats::kMinActivationBroadcastPeriodNs) {
268 StatsdStats::getInstance().noteActivationBroadcastGuardrailHit(uid);
269 VLOG("StatsD would've sent an activation broadcast but the rate limit stopped us.");
270 return;
271 }
272 }
273 auto activeConfigs = activeConfigsPerUid.find(uid);
274 if (activeConfigs != activeConfigsPerUid.end()) {
275 if (mSendActivationBroadcast(uid, activeConfigs->second)) {
276 VLOG("StatsD sent activation notice for uid %d", uid);
277 mLastActivationBroadcastTimes[uid] = currentTimestampNs;
278 }
279 } else {
280 std::vector<int64_t> emptyActiveConfigs;
281 if (mSendActivationBroadcast(uid, emptyActiveConfigs)) {
282 VLOG("StatsD sent EMPTY activation notice for uid %d", uid);
283 mLastActivationBroadcastTimes[uid] = currentTimestampNs;
284 }
285 }
286 }
287 }
288
GetActiveConfigs(const int uid,vector<int64_t> & outActiveConfigs)289 void StatsLogProcessor::GetActiveConfigs(const int uid, vector<int64_t>& outActiveConfigs) {
290 std::lock_guard<std::mutex> lock(mMetricsMutex);
291 GetActiveConfigsLocked(uid, outActiveConfigs);
292 }
293
GetActiveConfigsLocked(const int uid,vector<int64_t> & outActiveConfigs)294 void StatsLogProcessor::GetActiveConfigsLocked(const int uid, vector<int64_t>& outActiveConfigs) {
295 outActiveConfigs.clear();
296 for (auto& pair : mMetricsManagers) {
297 if (pair.first.GetUid() == uid && pair.second->isActive()) {
298 outActiveConfigs.push_back(pair.first.GetId());
299 }
300 }
301 }
302
OnConfigUpdated(const int64_t timestampNs,const ConfigKey & key,const StatsdConfig & config)303 void StatsLogProcessor::OnConfigUpdated(const int64_t timestampNs, const ConfigKey& key,
304 const StatsdConfig& config) {
305 std::lock_guard<std::mutex> lock(mMetricsMutex);
306 WriteDataToDiskLocked(key, timestampNs, CONFIG_UPDATED, NO_TIME_CONSTRAINTS);
307 OnConfigUpdatedLocked(timestampNs, key, config);
308 }
309
OnConfigUpdatedLocked(const int64_t timestampNs,const ConfigKey & key,const StatsdConfig & config)310 void StatsLogProcessor::OnConfigUpdatedLocked(
311 const int64_t timestampNs, const ConfigKey& key, const StatsdConfig& config) {
312 VLOG("Updated configuration for key %s", key.ToString().c_str());
313 sp<MetricsManager> newMetricsManager =
314 new MetricsManager(key, config, mTimeBaseNs, timestampNs, mUidMap, mPullerManager,
315 mAnomalyAlarmMonitor, mPeriodicAlarmMonitor);
316 if (newMetricsManager->isConfigValid()) {
317 mUidMap->OnConfigUpdated(key);
318 newMetricsManager->refreshTtl(timestampNs);
319 mMetricsManagers[key] = newMetricsManager;
320 VLOG("StatsdConfig valid");
321 } else {
322 // If there is any error in the config, don't use it.
323 ALOGE("StatsdConfig NOT valid");
324 }
325 }
326
GetMetricsSize(const ConfigKey & key) const327 size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const {
328 std::lock_guard<std::mutex> lock(mMetricsMutex);
329 auto it = mMetricsManagers.find(key);
330 if (it == mMetricsManagers.end()) {
331 ALOGW("Config source %s does not exist", key.ToString().c_str());
332 return 0;
333 }
334 return it->second->byteSize();
335 }
336
dumpStates(int out,bool verbose)337 void StatsLogProcessor::dumpStates(int out, bool verbose) {
338 std::lock_guard<std::mutex> lock(mMetricsMutex);
339 FILE* fout = fdopen(out, "w");
340 if (fout == NULL) {
341 return;
342 }
343 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);
349 }
350
351 /*
352 * onDumpReport dumps serialized ConfigMetricsReportList into proto.
353 */
onDumpReport(const ConfigKey & key,const int64_t dumpTimeStampNs,const bool include_current_partial_bucket,const bool erase_data,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,ProtoOutputStream * proto)354 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
355 const bool include_current_partial_bucket,
356 const bool erase_data,
357 const DumpReportReason dumpReportReason,
358 const DumpLatency dumpLatency,
359 ProtoOutputStream* proto) {
360 std::lock_guard<std::mutex> lock(mMetricsMutex);
361
362 // Start of ConfigKey.
363 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);
367 // End of ConfigKey.
368
369 bool keepFile = false;
370 auto it = mMetricsManagers.find(key);
371 if (it != mMetricsManagers.end() && it->second->shouldPersistLocalHistory()) {
372 keepFile = true;
373 }
374
375 // Then, check stats-data directory to see there's any file containing
376 // ConfigMetricsReport from previous shutdowns to concatenate to reports.
377 StorageManager::appendConfigMetricsReport(
378 key, proto, erase_data && !keepFile /* should remove file after appending it */,
379 dumpReportReason == ADB_DUMP /*if caller is adb*/);
380
381 if (it != mMetricsManagers.end()) {
382 // This allows another broadcast to be sent within the rate-limit period if we get close to
383 // filling the buffer again soon.
384 mLastBroadcastTimes.erase(key);
385
386 vector<uint8_t> buffer;
387 onConfigMetricsReportLocked(key, dumpTimeStampNs, include_current_partial_bucket,
388 erase_data, dumpReportReason, dumpLatency,
389 false /* is this data going to be saved on disk */, &buffer);
390 proto->write(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS,
391 reinterpret_cast<char*>(buffer.data()), buffer.size());
392 } else {
393 ALOGW("Config source %s does not exist", key.ToString().c_str());
394 }
395 }
396
397 /*
398 * onDumpReport dumps serialized ConfigMetricsReportList into outData.
399 */
onDumpReport(const ConfigKey & key,const int64_t dumpTimeStampNs,const bool include_current_partial_bucket,const bool erase_data,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,vector<uint8_t> * outData)400 void StatsLogProcessor::onDumpReport(const ConfigKey& key, const int64_t dumpTimeStampNs,
401 const bool include_current_partial_bucket,
402 const bool erase_data,
403 const DumpReportReason dumpReportReason,
404 const DumpLatency dumpLatency,
405 vector<uint8_t>* outData) {
406 ProtoOutputStream proto;
407 onDumpReport(key, dumpTimeStampNs, include_current_partial_bucket, erase_data,
408 dumpReportReason, dumpLatency, &proto);
409
410 if (outData != nullptr) {
411 flushProtoToBuffer(proto, outData);
412 VLOG("output data size %zu", outData->size());
413 }
414
415 StatsdStats::getInstance().noteMetricsReportSent(key, proto.size());
416 }
417
418 /*
419 * onConfigMetricsReportLocked dumps serialized ConfigMetricsReport into outData.
420 */
onConfigMetricsReportLocked(const ConfigKey & key,const int64_t dumpTimeStampNs,const bool include_current_partial_bucket,const bool erase_data,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency,const bool dataSavedOnDisk,vector<uint8_t> * buffer)421 void StatsLogProcessor::onConfigMetricsReportLocked(
422 const ConfigKey& key, const int64_t dumpTimeStampNs,
423 const bool include_current_partial_bucket, const bool erase_data,
424 const DumpReportReason dumpReportReason, const DumpLatency dumpLatency,
425 const bool dataSavedOnDisk, vector<uint8_t>* buffer) {
426 // We already checked whether key exists in mMetricsManagers in
427 // WriteDataToDisk.
428 auto it = mMetricsManagers.find(key);
429 if (it == mMetricsManagers.end()) {
430 return;
431 }
432 int64_t lastReportTimeNs = it->second->getLastReportTimeNs();
433 int64_t lastReportWallClockNs = it->second->getLastReportWallClockNs();
434
435 std::set<string> str_set;
436
437 ProtoOutputStream tempProto;
438 // First, fill in ConfigMetricsReport using current data on memory, which
439 // starts from filling in StatsLogReport's.
440 it->second->onDumpReport(dumpTimeStampNs, include_current_partial_bucket, erase_data,
441 dumpLatency, &str_set, &tempProto);
442
443 // Fill in UidMap if there is at least one metric to report.
444 // This skips the uid map if it's an empty config.
445 if (it->second->getNumMetrics() > 0) {
446 uint64_t uidMapToken = tempProto.start(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP);
447 mUidMap->appendUidMap(
448 dumpTimeStampNs, key, it->second->hashStringInReport() ? &str_set : nullptr,
449 it->second->versionStringsInReport(), it->second->installerInReport(), &tempProto);
450 tempProto.end(uidMapToken);
451 }
452
453 // Fill in the timestamps.
454 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS,
455 (long long)lastReportTimeNs);
456 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS,
457 (long long)dumpTimeStampNs);
458 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_WALL_CLOCK_NANOS,
459 (long long)lastReportWallClockNs);
460 tempProto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_WALL_CLOCK_NANOS,
461 (long long)getWallClockNs());
462 // Dump report reason
463 tempProto.write(FIELD_TYPE_INT32 | FIELD_ID_DUMP_REPORT_REASON, dumpReportReason);
464
465 for (const auto& str : str_set) {
466 tempProto.write(FIELD_TYPE_STRING | FIELD_COUNT_REPEATED | FIELD_ID_STRINGS, str);
467 }
468
469 flushProtoToBuffer(tempProto, buffer);
470
471 // save buffer to disk if needed
472 if (erase_data && !dataSavedOnDisk && it->second->shouldPersistLocalHistory()) {
473 VLOG("save history to disk");
474 string file_name = StorageManager::getDataHistoryFileName((long)getWallClockSec(),
475 key.GetUid(), key.GetId());
476 StorageManager::writeFile(file_name.c_str(), buffer->data(), buffer->size());
477 }
478 }
479
resetConfigsLocked(const int64_t timestampNs,const std::vector<ConfigKey> & configs)480 void StatsLogProcessor::resetConfigsLocked(const int64_t timestampNs,
481 const std::vector<ConfigKey>& configs) {
482 for (const auto& key : configs) {
483 StatsdConfig config;
484 if (StorageManager::readConfigFromDisk(key, &config)) {
485 OnConfigUpdatedLocked(timestampNs, key, config);
486 StatsdStats::getInstance().noteConfigReset(key);
487 } else {
488 ALOGE("Failed to read backup config from disk for : %s", key.ToString().c_str());
489 auto it = mMetricsManagers.find(key);
490 if (it != mMetricsManagers.end()) {
491 it->second->refreshTtl(timestampNs);
492 }
493 }
494 }
495 }
496
resetIfConfigTtlExpiredLocked(const int64_t timestampNs)497 void StatsLogProcessor::resetIfConfigTtlExpiredLocked(const int64_t timestampNs) {
498 std::vector<ConfigKey> configKeysTtlExpired;
499 for (auto it = mMetricsManagers.begin(); it != mMetricsManagers.end(); it++) {
500 if (it->second != nullptr && !it->second->isInTtl(timestampNs)) {
501 configKeysTtlExpired.push_back(it->first);
502 }
503 }
504 if (configKeysTtlExpired.size() > 0) {
505 WriteDataToDiskLocked(CONFIG_RESET, NO_TIME_CONSTRAINTS);
506 resetConfigsLocked(timestampNs, configKeysTtlExpired);
507 }
508 }
509
OnConfigRemoved(const ConfigKey & key)510 void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
511 std::lock_guard<std::mutex> lock(mMetricsMutex);
512 auto it = mMetricsManagers.find(key);
513 if (it != mMetricsManagers.end()) {
514 WriteDataToDiskLocked(key, getElapsedRealtimeNs(), CONFIG_REMOVED,
515 NO_TIME_CONSTRAINTS);
516 mMetricsManagers.erase(it);
517 mUidMap->OnConfigRemoved(key);
518 }
519 StatsdStats::getInstance().noteConfigRemoved(key);
520
521 mLastBroadcastTimes.erase(key);
522
523 int uid = key.GetUid();
524 bool lastConfigForUid = true;
525 for (auto it : mMetricsManagers) {
526 if (it.first.GetUid() == uid) {
527 lastConfigForUid = false;
528 break;
529 }
530 }
531 if (lastConfigForUid) {
532 mLastActivationBroadcastTimes.erase(uid);
533 }
534
535 if (mMetricsManagers.empty()) {
536 mPullerManager->ForceClearPullerCache();
537 }
538 }
539
flushIfNecessaryLocked(int64_t timestampNs,const ConfigKey & key,MetricsManager & metricsManager)540 void StatsLogProcessor::flushIfNecessaryLocked(
541 int64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) {
542 auto lastCheckTime = mLastByteSizeTimes.find(key);
543 if (lastCheckTime != mLastByteSizeTimes.end()) {
544 if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
545 return;
546 }
547 }
548
549 // We suspect that the byteSize() computation is expensive, so we set a rate limit.
550 size_t totalBytes = metricsManager.byteSize();
551 mLastByteSizeTimes[key] = timestampNs;
552 bool requestDump = false;
553 if (totalBytes >
554 StatsdStats::kMaxMetricsBytesPerConfig) { // Too late. We need to start clearing data.
555 metricsManager.dropData(timestampNs);
556 StatsdStats::getInstance().noteDataDropped(key, totalBytes);
557 VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
558 } else if ((totalBytes > StatsdStats::kBytesPerConfigTriggerGetData) ||
559 (mOnDiskDataConfigs.find(key) != mOnDiskDataConfigs.end())) {
560 // Request to send a broadcast if:
561 // 1. in memory data > threshold OR
562 // 2. config has old data report on disk.
563 requestDump = true;
564 }
565
566 if (requestDump) {
567 // Send broadcast so that receivers can pull data.
568 auto lastBroadcastTime = mLastBroadcastTimes.find(key);
569 if (lastBroadcastTime != mLastBroadcastTimes.end()) {
570 if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) {
571 VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
572 return;
573 }
574 }
575 if (mSendBroadcast(key)) {
576 mOnDiskDataConfigs.erase(key);
577 VLOG("StatsD triggered data fetch for %s", key.ToString().c_str());
578 mLastBroadcastTimes[key] = timestampNs;
579 StatsdStats::getInstance().noteBroadcastSent(key);
580 }
581 }
582 }
583
WriteDataToDiskLocked(const ConfigKey & key,const int64_t timestampNs,const DumpReportReason dumpReportReason,const DumpLatency dumpLatency)584 void StatsLogProcessor::WriteDataToDiskLocked(const ConfigKey& key,
585 const int64_t timestampNs,
586 const DumpReportReason dumpReportReason,
587 const DumpLatency dumpLatency) {
588 if (mMetricsManagers.find(key) == mMetricsManagers.end() ||
589 !mMetricsManagers.find(key)->second->shouldWriteToDisk()) {
590 return;
591 }
592 vector<uint8_t> buffer;
593 onConfigMetricsReportLocked(key, timestampNs, true /* include_current_partial_bucket*/,
594 true /* erase_data */, dumpReportReason, dumpLatency, true,
595 &buffer);
596 string file_name =
597 StorageManager::getDataFileName((long)getWallClockSec(), key.GetUid(), key.GetId());
598 StorageManager::writeFile(file_name.c_str(), buffer.data(), buffer.size());
599
600 // We were able to write the ConfigMetricsReport to disk, so we should trigger collection ASAP.
601 mOnDiskDataConfigs.insert(key);
602 }
603
SaveActiveConfigsToDisk(int64_t currentTimeNs)604 void StatsLogProcessor::SaveActiveConfigsToDisk(int64_t currentTimeNs) {
605 std::lock_guard<std::mutex> lock(mMetricsMutex);
606 const int64_t timeNs = getElapsedRealtimeNs();
607 // Do not write to disk if we already have in the last few seconds.
608 if (static_cast<unsigned long long> (timeNs) <
609 mLastActiveMetricsWriteNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
610 ALOGI("Statsd skipping writing active metrics to disk. Already wrote data in last %d seconds",
611 WRITE_DATA_COOL_DOWN_SEC);
612 return;
613 }
614 mLastActiveMetricsWriteNs = timeNs;
615
616 ProtoOutputStream proto;
617 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, DEVICE_SHUTDOWN, &proto);
618
619 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
620 StorageManager::deleteFile(file_name.c_str());
621 android::base::unique_fd fd(
622 open(file_name.c_str(), O_WRONLY | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR));
623 if (fd == -1) {
624 ALOGE("Attempt to write %s but failed", file_name.c_str());
625 return;
626 }
627 proto.flush(fd.get());
628 }
629
WriteActiveConfigsToProtoOutputStream(int64_t currentTimeNs,const DumpReportReason reason,ProtoOutputStream * proto)630 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStream(
631 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) {
632 std::lock_guard<std::mutex> lock(mMetricsMutex);
633 WriteActiveConfigsToProtoOutputStreamLocked(currentTimeNs, reason, proto);
634 }
635
WriteActiveConfigsToProtoOutputStreamLocked(int64_t currentTimeNs,const DumpReportReason reason,ProtoOutputStream * proto)636 void StatsLogProcessor::WriteActiveConfigsToProtoOutputStreamLocked(
637 int64_t currentTimeNs, const DumpReportReason reason, ProtoOutputStream* proto) {
638 for (const auto& pair : mMetricsManagers) {
639 const sp<MetricsManager>& metricsManager = pair.second;
640 uint64_t configToken = proto->start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED |
641 FIELD_ID_ACTIVE_CONFIG_LIST_CONFIG);
642 metricsManager->writeActiveConfigToProtoOutputStream(currentTimeNs, reason, proto);
643 proto->end(configToken);
644 }
645 }
LoadActiveConfigsFromDisk()646 void StatsLogProcessor::LoadActiveConfigsFromDisk() {
647 std::lock_guard<std::mutex> lock(mMetricsMutex);
648 string file_name = StringPrintf("%s/active_metrics", STATS_ACTIVE_METRIC_DIR);
649 int fd = open(file_name.c_str(), O_RDONLY | O_CLOEXEC);
650 if (-1 == fd) {
651 VLOG("Attempt to read %s but failed", file_name.c_str());
652 StorageManager::deleteFile(file_name.c_str());
653 return;
654 }
655 string content;
656 if (!android::base::ReadFdToString(fd, &content)) {
657 ALOGE("Attempt to read %s but failed", file_name.c_str());
658 close(fd);
659 StorageManager::deleteFile(file_name.c_str());
660 return;
661 }
662
663 close(fd);
664
665 ActiveConfigList activeConfigList;
666 if (!activeConfigList.ParseFromString(content)) {
667 ALOGE("Attempt to read %s but failed; failed to load active configs", file_name.c_str());
668 StorageManager::deleteFile(file_name.c_str());
669 return;
670 }
671 // Passing in mTimeBaseNs only works as long as we only load from disk is when statsd starts.
672 SetConfigsActiveStateLocked(activeConfigList, mTimeBaseNs);
673 StorageManager::deleteFile(file_name.c_str());
674 }
675
SetConfigsActiveState(const ActiveConfigList & activeConfigList,int64_t currentTimeNs)676 void StatsLogProcessor::SetConfigsActiveState(const ActiveConfigList& activeConfigList,
677 int64_t currentTimeNs) {
678 std::lock_guard<std::mutex> lock(mMetricsMutex);
679 SetConfigsActiveStateLocked(activeConfigList, currentTimeNs);
680 }
681
SetConfigsActiveStateLocked(const ActiveConfigList & activeConfigList,int64_t currentTimeNs)682 void StatsLogProcessor::SetConfigsActiveStateLocked(const ActiveConfigList& activeConfigList,
683 int64_t currentTimeNs) {
684 for (int i = 0; i < activeConfigList.config_size(); i++) {
685 const auto& config = activeConfigList.config(i);
686 ConfigKey key(config.uid(), config.id());
687 auto it = mMetricsManagers.find(key);
688 if (it == mMetricsManagers.end()) {
689 ALOGE("No config found for config %s", key.ToString().c_str());
690 continue;
691 }
692 VLOG("Setting active config %s", key.ToString().c_str());
693 it->second->loadActiveConfig(config, currentTimeNs);
694 }
695 VLOG("Successfully loaded %d active configs.", activeConfigList.config_size());
696 }
697
WriteDataToDiskLocked(const DumpReportReason dumpReportReason,const DumpLatency dumpLatency)698 void StatsLogProcessor::WriteDataToDiskLocked(const DumpReportReason dumpReportReason,
699 const DumpLatency dumpLatency) {
700 const int64_t timeNs = getElapsedRealtimeNs();
701 // Do not write to disk if we already have in the last few seconds.
702 // This is to avoid overwriting files that would have the same name if we
703 // write twice in the same second.
704 if (static_cast<unsigned long long> (timeNs) <
705 mLastWriteTimeNs + WRITE_DATA_COOL_DOWN_SEC * NS_PER_SEC) {
706 ALOGI("Statsd skipping writing data to disk. Already wrote data in last %d seconds",
707 WRITE_DATA_COOL_DOWN_SEC);
708 return;
709 }
710 mLastWriteTimeNs = timeNs;
711 for (auto& pair : mMetricsManagers) {
712 WriteDataToDiskLocked(pair.first, timeNs, dumpReportReason, dumpLatency);
713 }
714 }
715
WriteDataToDisk(const DumpReportReason dumpReportReason,const DumpLatency dumpLatency)716 void StatsLogProcessor::WriteDataToDisk(const DumpReportReason dumpReportReason,
717 const DumpLatency dumpLatency) {
718 std::lock_guard<std::mutex> lock(mMetricsMutex);
719 WriteDataToDiskLocked(dumpReportReason, dumpLatency);
720 }
721
informPullAlarmFired(const int64_t timestampNs)722 void StatsLogProcessor::informPullAlarmFired(const int64_t timestampNs) {
723 std::lock_guard<std::mutex> lock(mMetricsMutex);
724 mPullerManager->OnAlarmFired(timestampNs);
725 }
726
getLastReportTimeNs(const ConfigKey & key)727 int64_t StatsLogProcessor::getLastReportTimeNs(const ConfigKey& key) {
728 auto it = mMetricsManagers.find(key);
729 if (it == mMetricsManagers.end()) {
730 return 0;
731 } else {
732 return it->second->getLastReportTimeNs();
733 }
734 }
735
notifyAppUpgrade(const int64_t & eventTimeNs,const string & apk,const int uid,const int64_t version)736 void StatsLogProcessor::notifyAppUpgrade(const int64_t& eventTimeNs, const string& apk,
737 const int uid, const int64_t version) {
738 std::lock_guard<std::mutex> lock(mMetricsMutex);
739 ALOGW("Received app upgrade");
740 for (auto it : mMetricsManagers) {
741 it.second->notifyAppUpgrade(eventTimeNs, apk, uid, version);
742 }
743 }
744
notifyAppRemoved(const int64_t & eventTimeNs,const string & apk,const int uid)745 void StatsLogProcessor::notifyAppRemoved(const int64_t& eventTimeNs, const string& apk,
746 const int uid) {
747 std::lock_guard<std::mutex> lock(mMetricsMutex);
748 ALOGW("Received app removed");
749 for (auto it : mMetricsManagers) {
750 it.second->notifyAppRemoved(eventTimeNs, apk, uid);
751 }
752 }
753
onUidMapReceived(const int64_t & eventTimeNs)754 void StatsLogProcessor::onUidMapReceived(const int64_t& eventTimeNs) {
755 std::lock_guard<std::mutex> lock(mMetricsMutex);
756 ALOGW("Received uid map");
757 for (auto it : mMetricsManagers) {
758 it.second->onUidMapReceived(eventTimeNs);
759 }
760 }
761
noteOnDiskData(const ConfigKey & key)762 void StatsLogProcessor::noteOnDiskData(const ConfigKey& key) {
763 std::lock_guard<std::mutex> lock(mMetricsMutex);
764 mOnDiskDataConfigs.insert(key);
765 }
766
767 } // namespace statsd
768 } // namespace os
769 } // namespace android
770