StatsLogProcessor.cpp revision 8f42ba0e2c70a441bc7821dd32d5bab1c562b062 
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 "stats_log_util.h"
25#include "android-base/stringprintf.h"
26#include "guardrail/StatsdStats.h"
27#include "metrics/CountMetricProducer.h"
28#include "external/StatsPullerManager.h"
29#include "stats_util.h"
30#include "storage/StorageManager.h"
31
32#include <log/log_event_list.h>
33#include <utils/Errors.h>
34#include <utils/SystemClock.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
61// const int FIELD_ID_METRICS = 1; // written in MetricsManager.cpp
62const int FIELD_ID_UID_MAP = 2;
63const int FIELD_ID_LAST_REPORT_ELAPSED_NANOS = 3;
64const int FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS = 4;
65
66#define STATS_DATA_DIR "/data/misc/stats-data"
67
68StatsLogProcessor::StatsLogProcessor(const sp<UidMap>& uidMap,
69                                     const sp<AnomalyMonitor>& anomalyMonitor,
70                                     const long timeBaseSec,
71                                     const std::function<void(const ConfigKey&)>& sendBroadcast)
72    : mUidMap(uidMap),
73      mAnomalyMonitor(anomalyMonitor),
74      mSendBroadcast(sendBroadcast),
75      mTimeBaseSec(timeBaseSec),
76      mLastLogTimestamp(0) {
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 updateUid(Value* value, int hostUid) {
94    int uid = value->int_value;
95    if (uid != hostUid) {
96        value->setInt(hostUid);
97    }
98}
99
100void StatsLogProcessor::mapIsolatedUidToHostUidIfNecessaryLocked(LogEvent* event) const {
101    if (android::util::kAtomsWithAttributionChain.find(event->GetTagId()) !=
102        android::util::kAtomsWithAttributionChain.end()) {
103        for (auto& value : *(event->getMutableValues())) {
104            if (value.mField.getPosAtDepth(0) > kAttributionField) {
105                break;
106            }
107            if (isAttributionUidField(value)) {
108                const int hostUid = mUidMap->getHostUidOrSelf(value.mValue.int_value);
109                updateUid(&value.mValue, hostUid);
110            }
111        }
112    } else if (android::util::kAtomsWithUidField.find(event->GetTagId()) !=
113                       android::util::kAtomsWithUidField.end() &&
114               event->getValues().size() > 0 && (event->getValues())[0].mValue.getType() == INT) {
115        Value& value = (*event->getMutableValues())[0].mValue;
116        const int hostUid = mUidMap->getHostUidOrSelf(value.int_value);
117        updateUid(&value, hostUid);
118    }
119}
120
121void StatsLogProcessor::onIsolatedUidChangedEventLocked(const LogEvent& event) {
122    status_t err = NO_ERROR, err2 = NO_ERROR, err3 = NO_ERROR;
123    bool is_create = event.GetBool(3, &err);
124    auto parent_uid = int(event.GetLong(1, &err2));
125    auto isolated_uid = int(event.GetLong(2, &err3));
126    if (err == NO_ERROR && err2 == NO_ERROR && err3 == NO_ERROR) {
127        if (is_create) {
128            mUidMap->assignIsolatedUid(isolated_uid, parent_uid);
129        } else {
130            mUidMap->removeIsolatedUid(isolated_uid, parent_uid);
131        }
132    } else {
133        ALOGE("Failed to parse uid in the isolated uid change event.");
134    }
135}
136
137void StatsLogProcessor::OnLogEvent(LogEvent* event) {
138    std::lock_guard<std::mutex> lock(mMetricsMutex);
139    if (event->GetElapsedTimestampNs() < mLastLogTimestamp) {
140        return;
141    }
142    mLastLogTimestamp = event->GetElapsedTimestampNs();
143    StatsdStats::getInstance().noteAtomLogged(
144        event->GetTagId(), event->GetElapsedTimestampNs() / NS_PER_SEC);
145
146    // Hard-coded logic to update the isolated uid's in the uid-map.
147    // The field numbers need to be currently updated by hand with atoms.proto
148    if (event->GetTagId() == android::util::ISOLATED_UID_CHANGED) {
149        onIsolatedUidChangedEventLocked(*event);
150    }
151
152    if (mMetricsManagers.empty()) {
153        return;
154    }
155
156    uint64_t curTimeSec = getElapsedRealtimeSec();
157    if (curTimeSec - mLastPullerCacheClearTimeSec > StatsdStats::kPullerCacheClearIntervalSec) {
158        mStatsPullerManager.ClearPullerCacheIfNecessary(curTimeSec);
159        mLastPullerCacheClearTimeSec = curTimeSec;
160    }
161
162    if (event->GetTagId() != android::util::ISOLATED_UID_CHANGED) {
163        // Map the isolated uid to host uid if necessary.
164        mapIsolatedUidToHostUidIfNecessaryLocked(event);
165    }
166
167    // pass the event to metrics managers.
168    for (auto& pair : mMetricsManagers) {
169        pair.second->onLogEvent(*event);
170        flushIfNecessaryLocked(event->GetElapsedTimestampNs(), pair.first, *(pair.second));
171    }
172}
173
174void StatsLogProcessor::OnConfigUpdated(const ConfigKey& key, const StatsdConfig& config) {
175    std::lock_guard<std::mutex> lock(mMetricsMutex);
176    VLOG("Updated configuration for key %s", key.ToString().c_str());
177    sp<MetricsManager> newMetricsManager = new MetricsManager(key, config, mTimeBaseSec, mUidMap);
178    auto it = mMetricsManagers.find(key);
179    if (it == mMetricsManagers.end() && mMetricsManagers.size() > StatsdStats::kMaxConfigCount) {
180        ALOGE("Can't accept more configs!");
181        return;
182    }
183
184    if (newMetricsManager->isConfigValid()) {
185        mUidMap->OnConfigUpdated(key);
186        newMetricsManager->setAnomalyMonitor(mAnomalyMonitor);
187        if (newMetricsManager->shouldAddUidMapListener()) {
188            // We have to add listener after the MetricsManager is constructed because it's
189            // not safe to create wp or sp from this pointer inside its constructor.
190            mUidMap->addListener(newMetricsManager.get());
191        }
192        mMetricsManagers[key] = newMetricsManager;
193        // Why doesn't this work? mMetricsManagers.insert({key, std::move(newMetricsManager)});
194        VLOG("StatsdConfig valid");
195    } else {
196        // If there is any error in the config, don't use it.
197        ALOGE("StatsdConfig NOT valid");
198    }
199}
200
201size_t StatsLogProcessor::GetMetricsSize(const ConfigKey& key) const {
202    std::lock_guard<std::mutex> lock(mMetricsMutex);
203    auto it = mMetricsManagers.find(key);
204    if (it == mMetricsManagers.end()) {
205        ALOGW("Config source %s does not exist", key.ToString().c_str());
206        return 0;
207    }
208    return it->second->byteSize();
209}
210
211void StatsLogProcessor::dumpStates(FILE* out, bool verbose) {
212    std::lock_guard<std::mutex> lock(mMetricsMutex);
213    fprintf(out, "MetricsManager count: %lu\n", (unsigned long)mMetricsManagers.size());
214    for (auto metricsManager : mMetricsManagers) {
215        metricsManager.second->dumpStates(out, verbose);
216    }
217}
218
219void StatsLogProcessor::onDumpReport(const ConfigKey& key, const uint64_t dumpTimeStampNs,
220                                     vector<uint8_t>* outData) {
221    std::lock_guard<std::mutex> lock(mMetricsMutex);
222    onDumpReportLocked(key, dumpTimeStampNs, outData);
223}
224
225void StatsLogProcessor::onDumpReportLocked(const ConfigKey& key, const uint64_t dumpTimeStampNs,
226                                           vector<uint8_t>* outData) {
227    auto it = mMetricsManagers.find(key);
228    if (it == mMetricsManagers.end()) {
229        ALOGW("Config source %s does not exist", key.ToString().c_str());
230        return;
231    }
232
233    // This allows another broadcast to be sent within the rate-limit period if we get close to
234    // filling the buffer again soon.
235    mLastBroadcastTimes.erase(key);
236
237    ProtoOutputStream proto;
238
239    // Start of ConfigKey.
240    long long configKeyToken = proto.start(FIELD_TYPE_MESSAGE | FIELD_ID_CONFIG_KEY);
241    proto.write(FIELD_TYPE_INT32 | FIELD_ID_UID, key.GetUid());
242    proto.write(FIELD_TYPE_INT64 | FIELD_ID_ID, (long long)key.GetId());
243    proto.end(configKeyToken);
244    // End of ConfigKey.
245
246    // Start of ConfigMetricsReport (reports).
247    long long reportsToken =
248            proto.start(FIELD_TYPE_MESSAGE | FIELD_COUNT_REPEATED | FIELD_ID_REPORTS);
249
250    int64_t lastReportTimeNs = it->second->getLastReportTimeNs();
251    // First, fill in ConfigMetricsReport using current data on memory, which
252    // starts from filling in StatsLogReport's.
253    it->second->onDumpReport(dumpTimeStampNs, &proto);
254
255    // Fill in UidMap.
256    auto uidMap = mUidMap->getOutput(key);
257    const int uidMapSize = uidMap.ByteSize();
258    char uidMapBuffer[uidMapSize];
259    uidMap.SerializeToArray(&uidMapBuffer[0], uidMapSize);
260    proto.write(FIELD_TYPE_MESSAGE | FIELD_ID_UID_MAP, uidMapBuffer, uidMapSize);
261
262    // Fill in the timestamps.
263    proto.write(FIELD_TYPE_INT64 | FIELD_ID_LAST_REPORT_ELAPSED_NANOS,
264                (long long)lastReportTimeNs);
265    proto.write(FIELD_TYPE_INT64 | FIELD_ID_CURRENT_REPORT_ELAPSED_NANOS,
266                (long long)dumpTimeStampNs);
267
268    // End of ConfigMetricsReport (reports).
269    proto.end(reportsToken);
270
271    // Then, check stats-data directory to see there's any file containing
272    // ConfigMetricsReport from previous shutdowns to concatenate to reports.
273    StorageManager::appendConfigMetricsReport(proto);
274
275    if (outData != nullptr) {
276        outData->clear();
277        outData->resize(proto.size());
278        size_t pos = 0;
279        auto iter = proto.data();
280        while (iter.readBuffer() != NULL) {
281            size_t toRead = iter.currentToRead();
282            std::memcpy(&((*outData)[pos]), iter.readBuffer(), toRead);
283            pos += toRead;
284            iter.rp()->move(toRead);
285        }
286    }
287
288    StatsdStats::getInstance().noteMetricsReportSent(key);
289}
290
291void StatsLogProcessor::OnConfigRemoved(const ConfigKey& key) {
292    std::lock_guard<std::mutex> lock(mMetricsMutex);
293    auto it = mMetricsManagers.find(key);
294    if (it != mMetricsManagers.end()) {
295        mMetricsManagers.erase(it);
296        mUidMap->OnConfigRemoved(key);
297    }
298    StatsdStats::getInstance().noteConfigRemoved(key);
299
300    mLastBroadcastTimes.erase(key);
301
302    if (mMetricsManagers.empty()) {
303        mStatsPullerManager.ForceClearPullerCache();
304    }
305}
306
307void StatsLogProcessor::flushIfNecessaryLocked(
308    uint64_t timestampNs, const ConfigKey& key, MetricsManager& metricsManager) {
309    auto lastCheckTime = mLastByteSizeTimes.find(key);
310    if (lastCheckTime != mLastByteSizeTimes.end()) {
311        if (timestampNs - lastCheckTime->second < StatsdStats::kMinByteSizeCheckPeriodNs) {
312            return;
313        }
314    }
315
316    // We suspect that the byteSize() computation is expensive, so we set a rate limit.
317    size_t totalBytes = metricsManager.byteSize();
318    mLastByteSizeTimes[key] = timestampNs;
319    if (totalBytes >
320        StatsdStats::kMaxMetricsBytesPerConfig) {  // Too late. We need to start clearing data.
321        // TODO(b/70571383): By 12/15/2017 add API to drop data directly
322        ProtoOutputStream proto;
323        metricsManager.onDumpReport(time(nullptr) * NS_PER_SEC, &proto);
324        StatsdStats::getInstance().noteDataDropped(key);
325        VLOG("StatsD had to toss out metrics for %s", key.ToString().c_str());
326    } else if (totalBytes > .9 * StatsdStats::kMaxMetricsBytesPerConfig) {
327        // Send broadcast so that receivers can pull data.
328        auto lastBroadcastTime = mLastBroadcastTimes.find(key);
329        if (lastBroadcastTime != mLastBroadcastTimes.end()) {
330            if (timestampNs - lastBroadcastTime->second < StatsdStats::kMinBroadcastPeriodNs) {
331                VLOG("StatsD would've sent a broadcast but the rate limit stopped us.");
332                return;
333            }
334        }
335        mLastBroadcastTimes[key] = timestampNs;
336        VLOG("StatsD requesting broadcast for %s", key.ToString().c_str());
337        mSendBroadcast(key);
338        StatsdStats::getInstance().noteBroadcastSent(key);
339    }
340}
341
342void StatsLogProcessor::WriteDataToDisk() {
343    std::lock_guard<std::mutex> lock(mMetricsMutex);
344    for (auto& pair : mMetricsManagers) {
345        const ConfigKey& key = pair.first;
346        vector<uint8_t> data;
347        onDumpReportLocked(key, time(nullptr) * NS_PER_SEC, &data);
348        // TODO: Add a guardrail to prevent accumulation of file on disk.
349        string file_name = StringPrintf("%s/%ld_%d_%lld", STATS_DATA_DIR,
350             (long)getWallClockSec(), key.GetUid(), (long long)key.GetId());
351        StorageManager::writeFile(file_name.c_str(), &data[0], data.size());
352    }
353}
354
355}  // namespace statsd
356}  // namespace os
357}  // namespace android
358