504 lines
14 KiB
C++
504 lines
14 KiB
C++
/*
|
|
* Copyright (C) 2012-2014 The Android Open Source Project
|
|
*
|
|
* Licensed under the Apache License, Version 2.0 (the "License");
|
|
* you may not use this file except in compliance with the License.
|
|
* You may obtain a copy of the License at
|
|
*
|
|
* http://www.apache.org/licenses/LICENSE-2.0
|
|
*
|
|
* Unless required by applicable law or agreed to in writing, software
|
|
* distributed under the License is distributed on an "AS IS" BASIS,
|
|
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
|
* See the License for the specific language governing permissions and
|
|
* limitations under the License.
|
|
*/
|
|
|
|
#include <ctype.h>
|
|
#include <stdio.h>
|
|
#include <stdlib.h>
|
|
#include <string.h>
|
|
#include <sys/user.h>
|
|
#include <time.h>
|
|
#include <unistd.h>
|
|
|
|
#include <cutils/properties.h>
|
|
#include <log/logger.h>
|
|
|
|
#include "LogBuffer.h"
|
|
#include "LogReader.h"
|
|
#include "LogStatistics.h"
|
|
#include "LogWhiteBlackList.h"
|
|
|
|
// Default
|
|
#define LOG_BUFFER_SIZE (256 * 1024) // Tuned on a per-platform basis here?
|
|
#define log_buffer_size(id) mMaxSize[id]
|
|
#define LOG_BUFFER_MIN_SIZE (64 * 1024UL)
|
|
#define LOG_BUFFER_MAX_SIZE (256 * 1024 * 1024UL)
|
|
|
|
static bool valid_size(unsigned long value) {
|
|
if ((value < LOG_BUFFER_MIN_SIZE) || (LOG_BUFFER_MAX_SIZE < value)) {
|
|
return false;
|
|
}
|
|
|
|
long pages = sysconf(_SC_PHYS_PAGES);
|
|
if (pages < 1) {
|
|
return true;
|
|
}
|
|
|
|
long pagesize = sysconf(_SC_PAGESIZE);
|
|
if (pagesize <= 1) {
|
|
pagesize = PAGE_SIZE;
|
|
}
|
|
|
|
// maximum memory impact a somewhat arbitrary ~3%
|
|
pages = (pages + 31) / 32;
|
|
unsigned long maximum = pages * pagesize;
|
|
|
|
if ((maximum < LOG_BUFFER_MIN_SIZE) || (LOG_BUFFER_MAX_SIZE < maximum)) {
|
|
return true;
|
|
}
|
|
|
|
return value <= maximum;
|
|
}
|
|
|
|
static unsigned long property_get_size(const char *key) {
|
|
char property[PROPERTY_VALUE_MAX];
|
|
property_get(key, property, "");
|
|
|
|
char *cp;
|
|
unsigned long value = strtoul(property, &cp, 10);
|
|
|
|
switch(*cp) {
|
|
case 'm':
|
|
case 'M':
|
|
value *= 1024;
|
|
/* FALLTHRU */
|
|
case 'k':
|
|
case 'K':
|
|
value *= 1024;
|
|
/* FALLTHRU */
|
|
case '\0':
|
|
break;
|
|
|
|
default:
|
|
value = 0;
|
|
}
|
|
|
|
if (!valid_size(value)) {
|
|
value = 0;
|
|
}
|
|
|
|
return value;
|
|
}
|
|
|
|
LogBuffer::LogBuffer(LastLogTimes *times)
|
|
: mTimes(*times) {
|
|
pthread_mutex_init(&mLogElementsLock, NULL);
|
|
dgram_qlen_statistics = false;
|
|
|
|
static const char global_tuneable[] = "persist.logd.size"; // Settings App
|
|
static const char global_default[] = "ro.logd.size"; // BoardConfig.mk
|
|
|
|
unsigned long default_size = property_get_size(global_tuneable);
|
|
if (!default_size) {
|
|
default_size = property_get_size(global_default);
|
|
}
|
|
|
|
log_id_for_each(i) {
|
|
char key[PROP_NAME_MAX];
|
|
|
|
snprintf(key, sizeof(key), "%s.%s",
|
|
global_tuneable, android_log_id_to_name(i));
|
|
unsigned long property_size = property_get_size(key);
|
|
|
|
if (!property_size) {
|
|
snprintf(key, sizeof(key), "%s.%s",
|
|
global_default, android_log_id_to_name(i));
|
|
property_size = property_get_size(key);
|
|
}
|
|
|
|
if (!property_size) {
|
|
property_size = default_size;
|
|
}
|
|
|
|
if (!property_size) {
|
|
property_size = LOG_BUFFER_SIZE;
|
|
}
|
|
|
|
if (setSize(i, property_size)) {
|
|
setSize(i, LOG_BUFFER_MIN_SIZE);
|
|
}
|
|
}
|
|
}
|
|
|
|
void LogBuffer::log(log_id_t log_id, log_time realtime,
|
|
uid_t uid, pid_t pid, pid_t tid,
|
|
const char *msg, unsigned short len) {
|
|
if ((log_id >= LOG_ID_MAX) || (log_id < 0)) {
|
|
return;
|
|
}
|
|
LogBufferElement *elem = new LogBufferElement(log_id, realtime,
|
|
uid, pid, tid, msg, len);
|
|
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
|
|
// Insert elements in time sorted order if possible
|
|
// NB: if end is region locked, place element at end of list
|
|
LogBufferElementCollection::iterator it = mLogElements.end();
|
|
LogBufferElementCollection::iterator last = it;
|
|
while (--it != mLogElements.begin()) {
|
|
if ((*it)->getRealTime() <= realtime) {
|
|
// halves the peak performance, use with caution
|
|
if (dgram_qlen_statistics) {
|
|
LogBufferElementCollection::iterator ib = it;
|
|
unsigned short buckets, num = 1;
|
|
for (unsigned short i = 0; (buckets = stats.dgram_qlen(i)); ++i) {
|
|
buckets -= num;
|
|
num += buckets;
|
|
while (buckets && (--ib != mLogElements.begin())) {
|
|
--buckets;
|
|
}
|
|
if (buckets) {
|
|
break;
|
|
}
|
|
stats.recordDiff(
|
|
elem->getRealTime() - (*ib)->getRealTime(), i);
|
|
}
|
|
}
|
|
break;
|
|
}
|
|
last = it;
|
|
}
|
|
|
|
if (last == mLogElements.end()) {
|
|
mLogElements.push_back(elem);
|
|
} else {
|
|
log_time end = log_time::EPOCH;
|
|
bool end_set = false;
|
|
bool end_always = false;
|
|
|
|
LogTimeEntry::lock();
|
|
|
|
LastLogTimes::iterator t = mTimes.begin();
|
|
while(t != mTimes.end()) {
|
|
LogTimeEntry *entry = (*t);
|
|
if (entry->owned_Locked()) {
|
|
if (!entry->mNonBlock) {
|
|
end_always = true;
|
|
break;
|
|
}
|
|
if (!end_set || (end <= entry->mEnd)) {
|
|
end = entry->mEnd;
|
|
end_set = true;
|
|
}
|
|
}
|
|
t++;
|
|
}
|
|
|
|
if (end_always
|
|
|| (end_set && (end >= (*last)->getMonotonicTime()))) {
|
|
mLogElements.push_back(elem);
|
|
} else {
|
|
mLogElements.insert(last,elem);
|
|
}
|
|
|
|
LogTimeEntry::unlock();
|
|
}
|
|
|
|
stats.add(len, log_id, uid, pid);
|
|
maybePrune(log_id);
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
}
|
|
|
|
// If we're using more than 256K of memory for log entries, prune
|
|
// at least 10% of the log entries.
|
|
//
|
|
// mLogElementsLock must be held when this function is called.
|
|
void LogBuffer::maybePrune(log_id_t id) {
|
|
size_t sizes = stats.sizes(id);
|
|
if (sizes > log_buffer_size(id)) {
|
|
size_t sizeOver90Percent = sizes - ((log_buffer_size(id) * 9) / 10);
|
|
size_t elements = stats.elements(id);
|
|
unsigned long pruneRows = elements * sizeOver90Percent / sizes;
|
|
elements /= 10;
|
|
if (pruneRows <= elements) {
|
|
pruneRows = elements;
|
|
}
|
|
prune(id, pruneRows);
|
|
}
|
|
}
|
|
|
|
// prune "pruneRows" of type "id" from the buffer.
|
|
//
|
|
// mLogElementsLock must be held when this function is called.
|
|
void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
|
|
LogTimeEntry *oldest = NULL;
|
|
|
|
LogTimeEntry::lock();
|
|
|
|
// Region locked?
|
|
LastLogTimes::iterator t = mTimes.begin();
|
|
while(t != mTimes.end()) {
|
|
LogTimeEntry *entry = (*t);
|
|
if (entry->owned_Locked()
|
|
&& (!oldest || (oldest->mStart > entry->mStart))) {
|
|
oldest = entry;
|
|
}
|
|
t++;
|
|
}
|
|
|
|
LogBufferElementCollection::iterator it;
|
|
|
|
if (caller_uid != AID_ROOT) {
|
|
for(it = mLogElements.begin(); it != mLogElements.end();) {
|
|
LogBufferElement *e = *it;
|
|
|
|
if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
|
|
break;
|
|
}
|
|
|
|
if (e->getLogId() != id) {
|
|
++it;
|
|
continue;
|
|
}
|
|
|
|
uid_t uid = e->getUid();
|
|
|
|
if (uid == caller_uid) {
|
|
it = mLogElements.erase(it);
|
|
unsigned short len = e->getMsgLen();
|
|
stats.subtract(len, id, uid, e->getPid());
|
|
delete e;
|
|
pruneRows--;
|
|
if (pruneRows == 0) {
|
|
break;
|
|
}
|
|
} else {
|
|
++it;
|
|
}
|
|
}
|
|
LogTimeEntry::unlock();
|
|
return;
|
|
}
|
|
|
|
// prune by worst offender by uid
|
|
while (pruneRows > 0) {
|
|
// recalculate the worst offender on every batched pass
|
|
uid_t worst = (uid_t) -1;
|
|
size_t worst_sizes = 0;
|
|
size_t second_worst_sizes = 0;
|
|
|
|
if ((id != LOG_ID_CRASH) && mPrune.worstUidEnabled()) {
|
|
LidStatistics &l = stats.id(id);
|
|
l.sort();
|
|
UidStatisticsCollection::iterator iu = l.begin();
|
|
if (iu != l.end()) {
|
|
UidStatistics *u = *iu;
|
|
worst = u->getUid();
|
|
worst_sizes = u->sizes();
|
|
if (++iu != l.end()) {
|
|
second_worst_sizes = (*iu)->sizes();
|
|
}
|
|
}
|
|
}
|
|
|
|
bool kick = false;
|
|
for(it = mLogElements.begin(); it != mLogElements.end();) {
|
|
LogBufferElement *e = *it;
|
|
|
|
if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
|
|
break;
|
|
}
|
|
|
|
if (e->getLogId() != id) {
|
|
++it;
|
|
continue;
|
|
}
|
|
|
|
uid_t uid = e->getUid();
|
|
|
|
if (uid == worst) {
|
|
it = mLogElements.erase(it);
|
|
unsigned short len = e->getMsgLen();
|
|
stats.subtract(len, id, worst, e->getPid());
|
|
delete e;
|
|
kick = true;
|
|
pruneRows--;
|
|
if ((pruneRows == 0) || (worst_sizes < second_worst_sizes)) {
|
|
break;
|
|
}
|
|
worst_sizes -= len;
|
|
} else if (mPrune.naughty(e)) { // BlackListed
|
|
it = mLogElements.erase(it);
|
|
stats.subtract(e->getMsgLen(), id, uid, e->getPid());
|
|
delete e;
|
|
pruneRows--;
|
|
if (pruneRows == 0) {
|
|
break;
|
|
}
|
|
} else {
|
|
++it;
|
|
}
|
|
}
|
|
|
|
if (!kick || !mPrune.worstUidEnabled()) {
|
|
break; // the following loop will ask bad clients to skip/drop
|
|
}
|
|
}
|
|
|
|
bool whitelist = false;
|
|
it = mLogElements.begin();
|
|
while((pruneRows > 0) && (it != mLogElements.end())) {
|
|
LogBufferElement *e = *it;
|
|
if (e->getLogId() == id) {
|
|
if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
|
|
if (!whitelist) {
|
|
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
|
|
// kick a misbehaving log reader client off the island
|
|
oldest->release_Locked();
|
|
} else {
|
|
oldest->triggerSkip_Locked(pruneRows);
|
|
}
|
|
}
|
|
break;
|
|
}
|
|
|
|
if (mPrune.nice(e)) { // WhiteListed
|
|
whitelist = true;
|
|
it++;
|
|
continue;
|
|
}
|
|
|
|
it = mLogElements.erase(it);
|
|
stats.subtract(e->getMsgLen(), id, e->getUid(), e->getPid());
|
|
delete e;
|
|
pruneRows--;
|
|
} else {
|
|
it++;
|
|
}
|
|
}
|
|
|
|
if (whitelist && (pruneRows > 0)) {
|
|
it = mLogElements.begin();
|
|
while((it != mLogElements.end()) && (pruneRows > 0)) {
|
|
LogBufferElement *e = *it;
|
|
if (e->getLogId() == id) {
|
|
if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
|
|
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
|
|
// kick a misbehaving log reader client off the island
|
|
oldest->release_Locked();
|
|
} else {
|
|
oldest->triggerSkip_Locked(pruneRows);
|
|
}
|
|
break;
|
|
}
|
|
it = mLogElements.erase(it);
|
|
stats.subtract(e->getMsgLen(), id, e->getUid(), e->getPid());
|
|
delete e;
|
|
pruneRows--;
|
|
} else {
|
|
it++;
|
|
}
|
|
}
|
|
}
|
|
|
|
LogTimeEntry::unlock();
|
|
}
|
|
|
|
// clear all rows of type "id" from the buffer.
|
|
void LogBuffer::clear(log_id_t id, uid_t uid) {
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
prune(id, ULONG_MAX, uid);
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
}
|
|
|
|
// get the used space associated with "id".
|
|
unsigned long LogBuffer::getSizeUsed(log_id_t id) {
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
size_t retval = stats.sizes(id);
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
return retval;
|
|
}
|
|
|
|
// set the total space allocated to "id"
|
|
int LogBuffer::setSize(log_id_t id, unsigned long size) {
|
|
// Reasonable limits ...
|
|
if (!valid_size(size)) {
|
|
return -1;
|
|
}
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
log_buffer_size(id) = size;
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
return 0;
|
|
}
|
|
|
|
// get the total space allocated to "id"
|
|
unsigned long LogBuffer::getSize(log_id_t id) {
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
size_t retval = log_buffer_size(id);
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
return retval;
|
|
}
|
|
|
|
log_time LogBuffer::flushTo(
|
|
SocketClient *reader, const log_time start, bool privileged,
|
|
bool (*filter)(const LogBufferElement *element, void *arg), void *arg) {
|
|
LogBufferElementCollection::iterator it;
|
|
log_time max = start;
|
|
uid_t uid = reader->getUid();
|
|
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
for (it = mLogElements.begin(); it != mLogElements.end(); ++it) {
|
|
LogBufferElement *element = *it;
|
|
|
|
if (!privileged && (element->getUid() != uid)) {
|
|
continue;
|
|
}
|
|
|
|
if (element->getMonotonicTime() <= start) {
|
|
continue;
|
|
}
|
|
|
|
// NB: calling out to another object with mLogElementsLock held (safe)
|
|
if (filter && !(*filter)(element, arg)) {
|
|
continue;
|
|
}
|
|
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
|
|
// range locking in LastLogTimes looks after us
|
|
max = element->flushTo(reader);
|
|
|
|
if (max == element->FLUSH_ERROR) {
|
|
return max;
|
|
}
|
|
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
}
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
|
|
return max;
|
|
}
|
|
|
|
void LogBuffer::formatStatistics(char **strp, uid_t uid, unsigned int logMask) {
|
|
log_time oldest(CLOCK_MONOTONIC);
|
|
|
|
pthread_mutex_lock(&mLogElementsLock);
|
|
|
|
// Find oldest element in the log(s)
|
|
LogBufferElementCollection::iterator it;
|
|
for (it = mLogElements.begin(); it != mLogElements.end(); ++it) {
|
|
LogBufferElement *element = *it;
|
|
|
|
if ((logMask & (1 << element->getLogId()))) {
|
|
oldest = element->getMonotonicTime();
|
|
break;
|
|
}
|
|
}
|
|
|
|
stats.format(strp, uid, logMask, oldest);
|
|
|
|
pthread_mutex_unlock(&mLogElementsLock);
|
|
}
|