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