LogBuffer.cpp revision 64d6fe936253b336049c285369a56cf139bd002f 
1/*
2 * Copyright (C) 2012-2014 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#include <stdio.h>
18#include <string.h>
19#include <time.h>
20#include <unistd.h>
21
22#include <log/logger.h>
23
24#include "LogBuffer.h"
25#include "LogStatistics.h"
26#include "LogReader.h"
27
28#define LOG_BUFFER_SIZE (256 * 1024) // Tuned on a per-platform basis here?
29
30LogBuffer::LogBuffer(LastLogTimes *times)
31        : mTimes(*times) {
32    pthread_mutex_init(&mLogElementsLock, NULL);
33}
34
35void LogBuffer::log(log_id_t log_id, log_time realtime,
36                    uid_t uid, pid_t pid, const char *msg,
37                    unsigned short len) {
38    if ((log_id >= LOG_ID_MAX) || (log_id < 0)) {
39        return;
40    }
41    LogBufferElement *elem = new LogBufferElement(log_id, realtime,
42                                                  uid, pid, msg, len);
43
44    pthread_mutex_lock(&mLogElementsLock);
45
46    // Insert elements in time sorted order if possible
47    //  NB: if end is region locked, place element at end of list
48    LogBufferElementCollection::iterator it = mLogElements.end();
49    LogBufferElementCollection::iterator last = it;
50    while (--it != mLogElements.begin()) {
51        if ((*it)->getRealTime() <= realtime) {
52            break;
53        }
54        last = it;
55    }
56
57    if (last == mLogElements.end()) {
58        mLogElements.push_back(elem);
59    } else {
60        log_time end;
61        bool end_set = false;
62        bool end_always = false;
63
64        LogTimeEntry::lock();
65
66        LastLogTimes::iterator t = mTimes.begin();
67        while(t != mTimes.end()) {
68            LogTimeEntry *entry = (*t);
69            if (entry->owned_Locked()) {
70                if (!entry->mNonBlock) {
71                    end_always = true;
72                    break;
73                }
74                if (!end_set || (end <= entry->mEnd)) {
75                    end = entry->mEnd;
76                    end_set = true;
77                }
78            }
79            t++;
80        }
81
82        if (end_always
83                || (end_set && (end >= (*last)->getMonotonicTime()))) {
84            mLogElements.push_back(elem);
85        } else {
86            mLogElements.insert(last,elem);
87        }
88
89        LogTimeEntry::unlock();
90    }
91
92    stats.add(len, log_id, uid, pid);
93    maybePrune(log_id);
94    pthread_mutex_unlock(&mLogElementsLock);
95}
96
97// If we're using more than 256K of memory for log entries, prune
98// at least 10% of the log entries.
99//
100// mLogElementsLock must be held when this function is called.
101void LogBuffer::maybePrune(log_id_t id) {
102    size_t sizes = stats.sizes(id);
103    if (sizes > LOG_BUFFER_SIZE) {
104        size_t sizeOver90Percent = sizes - ((LOG_BUFFER_SIZE * 9) / 10);
105        size_t elements = stats.elements(id);
106        unsigned long pruneRows = elements * sizeOver90Percent / sizes;
107        elements /= 10;
108        if (pruneRows <= elements) {
109            pruneRows = elements;
110        }
111        prune(id, pruneRows);
112    }
113}
114
115// prune "pruneRows" of type "id" from the buffer.
116//
117// mLogElementsLock must be held when this function is called.
118void LogBuffer::prune(log_id_t id, unsigned long pruneRows) {
119    LogTimeEntry *oldest = NULL;
120
121    LogTimeEntry::lock();
122
123    // Region locked?
124    LastLogTimes::iterator t = mTimes.begin();
125    while(t != mTimes.end()) {
126        LogTimeEntry *entry = (*t);
127        if (entry->owned_Locked()
128                && (!oldest || (oldest->mStart > entry->mStart))) {
129            oldest = entry;
130        }
131        t++;
132    }
133
134    LogBufferElementCollection::iterator it;
135
136    // prune by worst offender by uid
137    while (pruneRows > 0) {
138        // recalculate the worst offender on every batched pass
139        uid_t worst = (uid_t) -1;
140        size_t worst_sizes = 0;
141        size_t second_worst_sizes = 0;
142
143        LidStatistics &l = stats.id(id);
144        UidStatisticsCollection::iterator iu;
145        for (iu = l.begin(); iu != l.end(); ++iu) {
146            UidStatistics *u = (*iu);
147            size_t sizes = u->sizes();
148            if (worst_sizes < sizes) {
149                second_worst_sizes = worst_sizes;
150                worst_sizes = sizes;
151                worst = u->getUid();
152            }
153            if ((second_worst_sizes < sizes) && (sizes < worst_sizes)) {
154                second_worst_sizes = sizes;
155            }
156        }
157
158        bool kick = false;
159        for(it = mLogElements.begin(); it != mLogElements.end();) {
160            LogBufferElement *e = *it;
161
162            if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
163                break;
164            }
165
166            if ((e->getLogId() == id) && (e->getUid() == worst)) {
167                it = mLogElements.erase(it);
168                unsigned short len = e->getMsgLen();
169                stats.subtract(len, id, worst, e->getPid());
170                delete e;
171                kick = true;
172                pruneRows--;
173                if ((pruneRows == 0) || (worst_sizes < second_worst_sizes)) {
174                    break;
175                }
176                worst_sizes -= len;
177            } else {
178                ++it;
179            }
180        }
181
182        if (!kick) {
183            break; // the following loop will ask bad clients to skip/drop
184        }
185    }
186
187    it = mLogElements.begin();
188    while((pruneRows > 0) && (it != mLogElements.end())) {
189        LogBufferElement *e = *it;
190        if (e->getLogId() == id) {
191            if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
192                if (stats.sizes(id) > (2 * LOG_BUFFER_SIZE)) {
193                    // kick a misbehaving log reader client off the island
194                    oldest->release_Locked();
195                } else {
196                    oldest->triggerSkip_Locked(pruneRows);
197                }
198                break;
199            }
200            it = mLogElements.erase(it);
201            stats.subtract(e->getMsgLen(), id, e->getUid(), e->getPid());
202            delete e;
203            pruneRows--;
204        } else {
205            it++;
206        }
207    }
208
209    LogTimeEntry::unlock();
210}
211
212// clear all rows of type "id" from the buffer.
213void LogBuffer::clear(log_id_t id) {
214    pthread_mutex_lock(&mLogElementsLock);
215    prune(id, ULONG_MAX);
216    pthread_mutex_unlock(&mLogElementsLock);
217}
218
219// get the used space associated with "id".
220unsigned long LogBuffer::getSizeUsed(log_id_t id) {
221    pthread_mutex_lock(&mLogElementsLock);
222    size_t retval = stats.sizes(id);
223    pthread_mutex_unlock(&mLogElementsLock);
224    return retval;
225}
226
227// get the total space allocated to "id"
228unsigned long LogBuffer::getSize(log_id_t /*id*/) {
229    return LOG_BUFFER_SIZE;
230}
231
232log_time LogBuffer::flushTo(
233        SocketClient *reader, const log_time start, bool privileged,
234        bool (*filter)(const LogBufferElement *element, void *arg), void *arg) {
235    LogBufferElementCollection::iterator it;
236    log_time max = start;
237    uid_t uid = reader->getUid();
238
239    pthread_mutex_lock(&mLogElementsLock);
240    for (it = mLogElements.begin(); it != mLogElements.end(); ++it) {
241        LogBufferElement *element = *it;
242
243        if (!privileged && (element->getUid() != uid)) {
244            continue;
245        }
246
247        if (element->getMonotonicTime() <= start) {
248            continue;
249        }
250
251        // NB: calling out to another object with mLogElementsLock held (safe)
252        if (filter && !(*filter)(element, arg)) {
253            continue;
254        }
255
256        pthread_mutex_unlock(&mLogElementsLock);
257
258        // range locking in LastLogTimes looks after us
259        max = element->flushTo(reader);
260
261        if (max == element->FLUSH_ERROR) {
262            return max;
263        }
264
265        pthread_mutex_lock(&mLogElementsLock);
266    }
267    pthread_mutex_unlock(&mLogElementsLock);
268
269    return max;
270}
271
272size_t LogBuffer::formatStatistics(char **strp, uid_t uid, unsigned int logMask) {
273    log_time oldest(CLOCK_MONOTONIC);
274
275    pthread_mutex_lock(&mLogElementsLock);
276
277    // Find oldest element in the log(s)
278    LogBufferElementCollection::iterator it;
279    for (it = mLogElements.begin(); it != mLogElements.end(); ++it) {
280        LogBufferElement *element = *it;
281
282        if ((logMask & (1 << element->getLogId()))) {
283            oldest = element->getMonotonicTime();
284            break;
285        }
286    }
287
288    size_t ret = stats.format(strp, uid, logMask, oldest);
289
290    pthread_mutex_unlock(&mLogElementsLock);
291
292    return ret;
293}
294