diff options
Diffstat (limited to 'logd')
-rw-r--r-- | logd/LogBuffer.cpp | 33 | ||||
-rw-r--r-- | logd/LogBuffer.h | 9 | ||||
-rw-r--r-- | logd/LogStatistics.cpp | 107 | ||||
-rw-r--r-- | logd/LogStatistics.h | 14 | ||||
-rw-r--r-- | logd/README.property | 3 | ||||
-rw-r--r-- | logd/main.cpp | 9 |
6 files changed, 106 insertions, 69 deletions
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index cd9ea20..8c1c344 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -93,9 +93,9 @@ static unsigned long property_get_size(const char *key) { } LogBuffer::LogBuffer(LastLogTimes *times) - : mTimes(*times) { + : dgramQlenStatistics(false) + , 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 @@ -150,10 +150,10 @@ void LogBuffer::log(log_id_t log_id, log_time realtime, while (--it != mLogElements.begin()) { if ((*it)->getRealTime() <= realtime) { // halves the peak performance, use with caution - if (dgram_qlen_statistics) { + if (dgramQlenStatistics) { LogBufferElementCollection::iterator ib = it; unsigned short buckets, num = 1; - for (unsigned short i = 0; (buckets = stats.dgram_qlen(i)); ++i) { + for (unsigned short i = 0; (buckets = stats.dgramQlen(i)); ++i) { buckets -= num; num += buckets; while (buckets && (--ib != mLogElements.begin())) { @@ -267,8 +267,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { if (uid == caller_uid) { it = mLogElements.erase(it); - unsigned short len = e->getMsgLen(); - stats.subtract(len, id, uid, e->getPid()); + stats.subtract(e->getMsgLen(), id, uid, e->getPid()); delete e; pruneRows--; if (pruneRows == 0) { @@ -318,23 +317,19 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { uid_t uid = e->getUid(); - if (uid == worst) { + if ((uid == worst) || mPrune.naughty(e)) { // Worst or BlackListed 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()); + stats.subtract(len, id, uid, e->getPid()); delete e; pruneRows--; - if (pruneRows == 0) { + if (uid == worst) { + kick = true; + if ((pruneRows == 0) || (worst_sizes < second_worst_sizes)) { + break; + } + worst_sizes -= len; + } else if (pruneRows == 0) { break; } } else { diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h index 4b982a8..879baea 100644 --- a/logd/LogBuffer.h +++ b/logd/LogBuffer.h @@ -37,8 +37,7 @@ class LogBuffer { pthread_mutex_t mLogElementsLock; LogStatistics stats; - - bool dgram_qlen_statistics; + bool dgramQlenStatistics; PruneList mPrune; @@ -66,7 +65,11 @@ public: void enableDgramQlenStatistics() { stats.enableDgramQlenStatistics(); - dgram_qlen_statistics = true; + dgramQlenStatistics = true; + } + + void enableStatistics() { + stats.enableStatistics(); } int initPrune(char *cp) { return mPrune.init(cp); } diff --git a/logd/LogStatistics.cpp b/logd/LogStatistics.cpp index 82f9165..6f3a088 100644 --- a/logd/LogStatistics.cpp +++ b/logd/LogStatistics.cpp @@ -51,11 +51,11 @@ PidStatistics::~PidStatistics() { } bool PidStatistics::pidGone() { - if (mGone) { + if (mGone || (pid == gone)) { return true; } - if (pid == gone) { - return true; + if (pid == 0) { + return false; } if (kill(pid, 0) && (errno != EPERM)) { mGone = true; @@ -90,9 +90,14 @@ void PidStatistics::addTotal(size_t size, size_t element) { } // must call free to release return value +// If only we could sniff our own logs for: +// <time> <pid> <pid> E AndroidRuntime: Process: <name>, PID: <pid> +// which debuggerd prints as a process is crashing. char *PidStatistics::pidToName(pid_t pid) { char *retval = NULL; - if (pid != gone) { + if (pid == 0) { // special case from auditd for kernel + retval = strdup("logd.auditd"); + } else if (pid != gone) { char buffer[512]; snprintf(buffer, sizeof(buffer), "/proc/%u/cmdline", pid); int fd = open(buffer, O_RDONLY); @@ -122,7 +127,7 @@ UidStatistics::~UidStatistics() { PidStatisticsCollection::iterator it; for (it = begin(); it != end();) { delete (*it); - it = Pids.erase(it); + it = erase(it); } } @@ -130,7 +135,7 @@ void UidStatistics::add(unsigned short size, pid_t pid) { mSizes += size; ++mElements; - PidStatistics *p; + PidStatistics *p = NULL; PidStatisticsCollection::iterator last; PidStatisticsCollection::iterator it; for (last = it = begin(); it != end(); last = it, ++it) { @@ -141,12 +146,12 @@ void UidStatistics::add(unsigned short size, pid_t pid) { } } // insert if the gone entry. - bool insert = (last != it) && (p->getPid() == p->gone); + bool insert_before_last = (last != it) && p && (p->getPid() == p->gone); p = new PidStatistics(pid, pidToName(pid)); - if (insert) { - Pids.insert(last, p); + if (insert_before_last) { + insert(last, p); } else { - Pids.push_back(p); + push_back(p); } p->add(size); } @@ -163,17 +168,17 @@ void UidStatistics::subtract(unsigned short size, pid_t pid) { size_t szsTotal = p->sizesTotal(); size_t elsTotal = p->elementsTotal(); delete p; - Pids.erase(it); + erase(it); it = end(); --it; if (it == end()) { p = new PidStatistics(p->gone); - Pids.push_back(p); + push_back(p); } else { p = *it; if (p->getPid() != p->gone) { p = new PidStatistics(p->gone); - Pids.push_back(p); + push_back(p); } } p->addTotal(szsTotal, elsTotal); @@ -194,8 +199,8 @@ void UidStatistics::sort() { PidStatistics *n = (*it); if ((n->getPid() != n->gone) && (n->sizes() > l->sizes())) { pass = true; - Pids.erase(it); - Pids.insert(lt, n); + erase(it); + insert(lt, n); it = lt; n = l; } @@ -302,6 +307,10 @@ void LidStatistics::add(unsigned short size, uid_t uid, pid_t pid) { } void LidStatistics::subtract(unsigned short size, uid_t uid, pid_t pid) { + if (uid == (uid_t) -1) { // init + uid = (uid_t) AID_ROOT; + } + UidStatisticsCollection::iterator it; for (it = begin(); it != end(); ++it) { UidStatistics *u = *it; @@ -384,24 +393,25 @@ size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) { } LogStatistics::LogStatistics() - : start(CLOCK_MONOTONIC) { + : mStatistics(false) + , dgramQlenStatistics(false) + , start(CLOCK_MONOTONIC) { log_id_for_each(i) { mSizes[i] = 0; mElements[i] = 0; } - dgram_qlen_statistics = false; - for(unsigned short bucket = 0; dgram_qlen(bucket); ++bucket) { + for(unsigned short bucket = 0; dgramQlen(bucket); ++bucket) { mMinimum[bucket].tv_sec = mMinimum[bucket].tv_sec_max; mMinimum[bucket].tv_nsec = mMinimum[bucket].tv_nsec_max; } } -// Each bucket below represents a dgram_qlen of log messages. By +// Each bucket below represents a dgramQlen of log messages. By // finding the minimum period of time from start to finish -// of each dgram_qlen, we can get a performance expectation for +// of each dgramQlen, we can get a performance expectation for // the user space logger. The net result is that the period -// of time divided by the dgram_qlen will give us the average time +// of time divided by the dgramQlen will give us the average time // between log messages; at the point where the average time // is greater than the throughput capability of the logger // we will not longer require the benefits of the FIFO formed @@ -412,7 +422,7 @@ LogStatistics::LogStatistics() // // for example (reformatted): // -// Minimum time between log events per dgram_qlen: +// Minimum time between log events per dgramQlen: // 1 2 3 5 10 20 30 50 100 200 300 400 500 600 // 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5 // @@ -426,12 +436,12 @@ LogStatistics::LogStatistics() // a large engineering margin so the rule of thumb that lead us to 100 is // fine. // -// bucket dgram_qlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300 +// bucket dgramQlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300 const unsigned short LogStatistics::mBuckets[] = { 1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600 }; -unsigned short LogStatistics::dgram_qlen(unsigned short bucket) { +unsigned short LogStatistics::dgramQlen(unsigned short bucket) { if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) { return 0; } @@ -455,6 +465,9 @@ void LogStatistics::add(unsigned short size, log_id_t log_id, uid_t uid, pid_t pid) { mSizes[log_id] += size; ++mElements[log_id]; + if (!mStatistics) { + return; + } id(log_id).add(size, uid, pid); } @@ -462,6 +475,9 @@ void LogStatistics::subtract(unsigned short size, log_id_t log_id, uid_t uid, pid_t pid) { mSizes[log_id] -= size; --mElements[log_id]; + if (!mStatistics) { + return; + } id(log_id).subtract(size, uid, pid); } @@ -545,25 +561,28 @@ void LogStatistics::format(char **buf, spaces = 1; log_time t(CLOCK_MONOTONIC); - unsigned long long d = t.nsec() - start.nsec(); - string.appendFormat("\nTotal%4llu:%02llu:%02llu.%09llu", + unsigned long long d; + if (mStatistics) { + d = t.nsec() - start.nsec(); + string.appendFormat("\nTotal%4llu:%02llu:%02llu.%09llu", d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60, (d / NS_PER_SEC) % 60, d % NS_PER_SEC); - log_id_for_each(i) { - if (!(logMask & (1 << i))) { - continue; - } - oldLength = string.length(); - if (spaces < 0) { - spaces = 0; + log_id_for_each(i) { + if (!(logMask & (1 << i))) { + continue; + } + oldLength = string.length(); + if (spaces < 0) { + spaces = 0; + } + string.appendFormat("%*s%zu/%zu", spaces, "", + sizesTotal(i), elementsTotal(i)); + spaces += spaces_total + oldLength - string.length(); } - string.appendFormat("%*s%zu/%zu", spaces, "", - sizesTotal(i), elementsTotal(i)); - spaces += spaces_total + oldLength - string.length(); + spaces = 1; } - spaces = 1; d = t.nsec() - oldest.nsec(); string.appendFormat("\nNow%6llu:%02llu:%02llu.%09llu", d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60, @@ -689,23 +708,23 @@ void LogStatistics::format(char **buf, pids.clear(); } - if (dgram_qlen_statistics) { + if (dgramQlenStatistics) { const unsigned short spaces_time = 6; const unsigned long long max_seconds = 100000; spaces = 0; - string.append("\n\nMinimum time between log events per dgram_qlen:\n"); - for(unsigned short i = 0; dgram_qlen(i); ++i) { + string.append("\n\nMinimum time between log events per max_dgram_qlen:\n"); + for(unsigned short i = 0; dgramQlen(i); ++i) { oldLength = string.length(); if (spaces < 0) { spaces = 0; } - string.appendFormat("%*s%u", spaces, "", dgram_qlen(i)); + string.appendFormat("%*s%u", spaces, "", dgramQlen(i)); spaces += spaces_time + oldLength - string.length(); } string.append("\n"); spaces = 0; unsigned short n; - for(unsigned short i = 0; (n = dgram_qlen(i)); ++i) { + for(unsigned short i = 0; (n = dgramQlen(i)); ++i) { unsigned long long duration = minimum(i); if (duration) { duration /= n; @@ -727,8 +746,8 @@ void LogStatistics::format(char **buf, / (NS_PER_SEC / 1000)); } else if (duration >= (NS_PER_SEC / (1000000 / 10))) { string.appendFormat("%lluu", - (duration + (NS_PER_SEC / 2 / 1000000)) - / (NS_PER_SEC / 1000000)); + (duration + (NS_PER_SEC / 2 / 1000000)) + / (NS_PER_SEC / 1000000)); } else { string.appendFormat("%llun", duration); } diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h index 3733137..f6c4329 100644 --- a/logd/LogStatistics.h +++ b/logd/LogStatistics.h @@ -72,6 +72,10 @@ class UidStatistics { PidStatisticsCollection Pids; + void insert(PidStatisticsCollection::iterator i, PidStatistics *p) + { Pids.insert(i, p); } + void push_back(PidStatistics *p) { Pids.push_back(p); } + size_t mSizes; size_t mElements; @@ -81,6 +85,8 @@ public: PidStatisticsCollection::iterator begin() { return Pids.begin(); } PidStatisticsCollection::iterator end() { return Pids.end(); } + PidStatisticsCollection::iterator erase(PidStatisticsCollection::iterator i) + { return Pids.erase(i); } uid_t getUid() { return uid; } @@ -138,7 +144,8 @@ class LogStatistics { size_t mSizes[LOG_ID_MAX]; size_t mElements[LOG_ID_MAX]; - bool dgram_qlen_statistics; + bool mStatistics; + bool dgramQlenStatistics; static const unsigned short mBuckets[14]; log_time mMinimum[sizeof(mBuckets) / sizeof(mBuckets[0])]; @@ -150,8 +157,9 @@ public: LidStatistics &id(log_id_t log_id) { return LogIds[log_id]; } - void enableDgramQlenStatistics() { dgram_qlen_statistics = true; } - static unsigned short dgram_qlen(unsigned short bucket); + void enableDgramQlenStatistics() { dgramQlenStatistics = true; } + void enableStatistics() { mStatistics = true; } + static unsigned short dgramQlen(unsigned short bucket); unsigned long long minimum(unsigned short bucket); void recordDiff(log_time diff, unsigned short bucket); diff --git a/logd/README.property b/logd/README.property index f4b3c3c..b7fcece 100644 --- a/logd/README.property +++ b/logd/README.property @@ -4,6 +4,9 @@ name type default description logd.auditd bool true Enable selinux audit daemon logd.auditd.dmesg bool true selinux audit messages duplicated and sent on to dmesg log +logd.statistics bool depends Enable logcat -S statistics. +ro.config.low_ram bool false if true, logd.statistics default false +ro.build.type string if user, logd.statistics default false logd.statistics.dgram_qlen bool false Record dgram_qlen statistics. This represents a performance impact and is used to determine the platform's diff --git a/logd/main.cpp b/logd/main.cpp index 1e1a718..54da7e3 100644 --- a/logd/main.cpp +++ b/logd/main.cpp @@ -152,6 +152,15 @@ int main() { if (property_get_bool("logd.statistics.dgram_qlen", false)) { logBuf->enableDgramQlenStatistics(); } + { + char property[PROPERTY_VALUE_MAX]; + property_get("ro.build.type", property, ""); + if (property_get_bool("logd.statistics", + !!strcmp(property, "user") + && !property_get_bool("ro.config.low_ram", false))) { + logBuf->enableStatistics(); + } + } // LogReader listens on /dev/socket/logdr. When a client // connects, log entries in the LogBuffer are written to the client. |