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