StatsLogProcessor.cpp revision 861795096296ebbe6d5b147519ad52a43b4b957c 
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 true  // STOPSHIP if true
18#include "Log.h"
19#include "statslog.h"
20
21#include <android-base/file.h>
22#include <dirent.h>
23#include "StatsLogProcessor.h"
24#include "android-base/stringprintf.h"
25#include "guardrail/StatsdStats.h"
26#include "metrics/CountMetricProducer.h"
27#include "external/StatsPullerManager.h"
28#include "dimension.h"
29#include "field_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
36using namespace android;
37using android::base::StringPrintf;
38using android::util::FIELD_COUNT_REPEATED;
39using android::util::FIELD_TYPE_BOOL;
40using android::util::FIELD_TYPE_FLOAT;
41using android::util::FIELD_TYPE_INT32;
42using android::util::FIELD_TYPE_INT64;
43using android::util::FIELD_TYPE_MESSAGE;
44using android::util::FIELD_TYPE_STRING;
45using android::util::ProtoOutputStream;
46using std::make_unique;
47using std::unique_ptr;
48using std::vector;
49
50namespace android {
51namespace os {
52namespace statsd {
53
54// for ConfigMetricsReportList
55const int FIELD_ID_CONFIG_KEY = 1;
56const int FIELD_ID_REPORTS = 2;
57// for ConfigKey
58const int FIELD_ID_UID = 1;
59const int FIELD_ID_ID = 2;
60// for ConfigMetricsReport
61const int FIELD_ID_METRICS = 1;
62const int FIELD_ID_UID_MAP = 2;
63
64#define STATS_DATA_DIR "/data/misc/stats-data"
65
66StatsLogProcessor::StatsLogProcessor(const sp<UidMap>& uidMap,
67                                     const sp<AnomalyMonitor>& anomalyMonitor,
68                                     const long timeBaseSec,
69                                     const std::function<void(const ConfigKey&)>& sendBroadcast)
70    : mUidMap(uidMap),
71      mAnomalyMonitor(anomalyMonitor),
72      mSendBroadcast(sendBroadcast),
73      mTimeBaseSec(timeBaseSec) {
74    // On each initialization of StatsLogProcessor, check stats-data directory to see if there is
75    // any left over data to be read.
76    StorageManager::sendBroadcast(STATS_DATA_DIR, mSendBroadcast);
77    StatsPullerManager statsPullerManager;
78    statsPullerManager.SetTimeBaseSec(mTimeBaseSec);
79}
80
81StatsLogProcessor::~StatsLogProcessor() {
82}
83
84void StatsLogProcessor::onAnomalyAlarmFired(
85        const uint64_t timestampNs,
86        unordered_set<sp<const AnomalyAlarm>, SpHash<AnomalyAlarm>> anomalySet) {
87    std::lock_guard<std::mutex> lock(mMetricsMutex);
88    for (const auto& itr : mMetricsManagers) {
89        itr.second->onAnomalyAlarmFired(timestampNs, anomalySet);
90    }
91}
92
93void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const {
94    std::vector<Field> uidFields;
95    findFields(
96        event->getFieldValueMap(),
97        buildAttributionUidFieldMatcher(event->GetTagId(), Position::ANY),
98        &uidFields);
99    for (size_t i = 0; i < uidFields.size(); ++i) {
100        DimensionsValue* value = event->findFieldValueOrNull(uidFields[i]);
101        if (value != nullptr && value->value_case() == DimensionsValue::ValueCase::kValueInt) {
102            const int uid = mUidMap->getHostUidOrSelf(value->value_int());
103            value->set_value_int(uid);
104        }
105    }
106}
107
108void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
109    status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR;
110    bool is_create = event.GetBool(3, &err);
111    auto parent_uid = int(event.GetLong(1, &err2));
112    auto isolated_uid = int(event.GetLong(2, &err3));
113    if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) {
114        if (is_create) {
115            mUidMap->assignIsolatedUid(isolated_uid, parent_uid);
116        } else {
117            mUidMap->removeIsolatedUid(isolated_uid, parent_uid);
118        }
119    } else {
120        ALOGE("Failed to parse uid in the isolated uid change event.");
121    }
122}
123
124// TODO: what if statsd service restarts? How do we know what logs are already processed before?
125void StatsLogProcessor::OnLogEvent(LogEvent* event) {
126    std::lock_guard<std::mutex> lock(mMetricsMutex);
127    StatsdStats::getInstance().noteAtomLogged(
128        event->GetTagId(), event->GetTimestampNs() / NS_PER_SEC);
129
130    // Hard-coded logic to update the isolated uid's in the uid-map.
131    // The field numbers need to be currently updated by hand with atoms.proto
132    if (event->GetTagId() == android::util::ISOLATED_UID_CHANGED) {
133        onIsolatedUidChangedEventLocked(*event);
134    } else {
135        // Map the isolated uid to host uid if necessary.
136        mapIsolatedUidToHostUidIfNecessaryLocked(event);
137    }
138
139    // pass the event to metrics managers.
140    for (auto& pair : mMetricsManagers) {
141        pair.second->onLogEvent(*event);
142        flushIfNecessaryLocked(event->GetTimestampNs(), pair.first, *(pair.second));
143    }
144}
145
146void StatsLogProcessor::OnConfigUpdated(const ConfigKey& key, const StatsdConfig& config) {
147    std::lock_guard<std::mutex> lock(mMetricsMutex);
148    ALOGD("Updated configuration for key %s", key.ToString().c_str());
149    sp<MetricsManager> newMetricsManager = new MetricsManager(key, config, mTimeBaseSec, mUidMap);
150    auto it = mMetricsManagers.find(key);
151    if (it == mMetricsManagers.end() && mMetricsManagers.size() > StatsdStats::kMaxConfigCount) {
152        ALOGE("Can't accept more configs!");
153        return;
154    }
155
156    if (newMetricsManager->isConfigValid()) {
157        mUidMap->OnConfigUpdated(key);
158        newMetricsManager->setAnomalyMonitor(mAnomalyMonitor);
159        if (newMetricsManager->shouldAddUidMapListener()) {
160            // We have to add listener after the MetricsManager is constructed because it's
161            // not safe to create wp or sp from this pointer inside its constructor.
162            mUidMap->addListener(newMetricsManager.get());
163        }
164        mMetricsManagers[key] = newMetricsManager;
165        // Why doesn't this work? mMetricsManagers.insert({key, std::move(newMetricsManager)});
166        VLOG("StatsdConfig valid");
167    } else {
168        // If there is any error in the config, don't use it.
169        ALOGE("StatsdConfig NOT valid");
170    }
171}
172
173size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const {
174    std::lock_guard<std::mutex> lock(mMetricsMutex);
175    auto it = mMetricsManagers.find(key);
176    if (it == mMetricsManagers.end()) {
177        ALOGW("Config source %s does not exist", key.ToString().c_str());
178        return 0;
179    }
180    return it->second->byteSize();
181}
182
183void StatsLogProcessor::onDumpReport(const ConfigKey& key, const uint64_t& dumpTimeStampNs,
184                                     ConfigMetricsReportList* report) {
185    std::lock_guard<std::mutex> lock(mMetricsMutex);
186    auto it = mMetricsManagers.find(key);
187    if (it == mMetricsManagers.end()) {
188        ALOGW("Config source %s does not exist", key.ToString().c_str());
189        return;
190    }
191    report->mutable_config_key()->set_uid(key.GetUid());
192    report->mutable_config_key()->set_id(key.GetId());
193    ConfigMetricsReport* configMetricsReport = report->add_reports();
194    it->second->onDumpReport(dumpTimeStampNs, configMetricsReport);
195    // TODO: dump uid mapping.
196}
197
198void StatsLogProcessor::onDumpReport(const ConfigKey& key, vector<uint8_t>* outData) {
199    std::lock_guard<std::mutex> lock(mMetricsMutex);
200    onDumpReportLocked(key, outData);
201}
202
203void StatsLogProcessor::onDumpReportLocked(const ConfigKey& key, vector<uint8_t>* outData) {
204    auto it = mMetricsManagers.find(key);
205    if (it == mMetricsManagers.end()) {
206        ALOGW("Config source %s does not exist", key.ToString().c_str());
207        return;
208    }
209
210    // This allows another broadcast to be sent within the rate-limit period if we get close to
211    // filling the buffer again soon.
212    mLastBroadcastTimes.erase(key);
213
214    ProtoOutputStream proto;
215
216    // Start of ConfigKey.
217    long long configKeyToken = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY);
218    proto.write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid());
219    proto.write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId());
220    proto.end(configKeyToken);
221    // End of ConfigKey.
222
223    // Start of ConfigMetricsReport (reports).
224    long long reportsToken =
225            proto.start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS);
226
227    // First, fill in ConfigMetricsReport using current data on memory, which
228    // starts from filling in StatsLogReport's.
229    it->second->onDumpReport(&proto);
230
231    // Fill in UidMap.
232    auto uidMap = mUidMap->getOutput(key);
233    const int uidMapSize = uidMap.ByteSize();
234    char uidMapBuffer[uidMapSize];
235    uidMap.SerializeToArray(&uidMapBuffer[0], uidMapSize);
236    proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP, uidMapBuffer, uidMapSize);
237
238    // End of ConfigMetricsReport (reports).
239    proto.end(reportsToken);
240
241    // Then, check stats-data directory to see there's any file containing
242    // ConfigMetricsReport from previous shutdowns to concatenate to reports.
243    StorageManager::appendConfigMetricsReport(STATS_DATA_DIR, proto);
244
245    if (outData != nullptr) {
246        outData->clear();
247        outData->resize(proto.size());
248        size_t pos = 0;
249        auto iter = proto.data();
250        while (iter.readBuffer() != NULL) {
251            size_t toRead = iter.currentToRead();
252            std::memcpy(&((*outData)[pos]), iter.readBuffer(), toRead);
253            pos += toRead;
254            iter.rp()->move(toRead);
255        }
256    }
257    StatsdStats::getInstance().noteMetricsReportSent(key);
258}
259
260void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
261    std::lock_guard<std::mutex> lock(mMetricsMutex);
262    auto it = mMetricsManagers.find(key);
263    if (it != mMetricsManagers.end()) {
264        mMetricsManagers.erase(it);
265        mUidMap->OnConfigRemoved(key);
266    }
267    StatsdStats::getInstance().noteConfigRemoved(key);
268
269    mLastBroadcastTimes.erase(key);
270}
271
272void StatsLogProcessor::flushIfNecessaryLocked(
273    uint64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) {
274    auto lastCheckTime = mLastByteSizeTimes.find(key);
275    if (lastCheckTime != mLastByteSizeTimes.end()) {
276        if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
277            return;
278        }
279    }
280
281    // We suspect that the byteSize() computation is expensive, so we set a rate limit.
282    size_t totalBytes = metricsManager.byteSize();
283    mLastByteSizeTimes[key] = timestampNs;
284    if (totalBytes >
285        StatsdStats::kMaxMetricsBytesPerConfig) {  // Too late. We need to start clearing data.
286        // TODO(b/70571383): By 12/15/2017 add API to drop data directly
287        ProtoOutputStream proto;
288        metricsManager.onDumpReport(&proto);
289        StatsdStats::getInstance().noteDataDropped(key);
290        VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
291    } else if (totalBytes > .9 * StatsdStats::kMaxMetricsBytesPerConfig) {
292        // Send broadcast so that receivers can pull data.
293        auto lastBroadcastTime = mLastBroadcastTimes.find(key);
294        if (lastBroadcastTime != mLastBroadcastTimes.end()) {
295            if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) {
296                VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
297                return;
298            }
299        }
300        mLastBroadcastTimes[key] = timestampNs;
301        VLOG("StatsD requesting broadcast for %s", key.ToString().c_str());
302        mSendBroadcast(key);
303        StatsdStats::getInstance().noteBroadcastSent(key);
304    }
305}
306
307void StatsLogProcessor::WriteDataToDisk() {
308    std::lock_guard<std::mutex> lock(mMetricsMutex);
309    for (auto& pair : mMetricsManagers) {
310        const ConfigKey& key = pair.first;
311        vector<uint8_t> data;
312        onDumpReportLocked(key, &data);
313        // TODO: Add a guardrail to prevent accumulation of file on disk.
314        string file_name = StringPrintf("%s/%d-%lld-%ld", STATS_DATA_DIR, key.GetUid(),
315                                        (long long)key.GetId(), time(nullptr));
316        StorageManager::writeFile(file_name.c_str(), &data[0], data.size());
317    }
318}
319
320}  // namespace statsd
321}  // namespace os
322}  // namespace android
323