From 8894c395bfcb80f0bedea8fcc0e8ef51e51dc883 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Mon, 10 Aug 2015 10:23:56 -0700 Subject: [PATCH 1/6] logd: sizes > 1M prune in smaller batches (cherry pick from commit 62ab0fd4efeed313adf2fdf84167d754620c0ad1) Switch to 1% batch sizes from 10% when individual buffer size > 1M Bug: 22351810 Change-Id: Ifee570a54643ceb0ba767e1787e937f70cc90b72 --- logd/LogBuffer.cpp | 23 +++++++++++++++-------- 1 file changed, 15 insertions(+), 8 deletions(-) diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index 0f5071b62..b9e8973ac 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -218,18 +218,25 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, } // If we're using more than 256K of memory for log entries, prune -// at least 10% of the log entries. +// at least 10% of the log entries. For sizes above 1M, prune at +// least 1% 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; + unsigned long maxSize = log_buffer_size(id); + if (sizes > maxSize) { + size_t sizeOver, minElements, elements = stats.elements(id); + if (maxSize > (4 * LOG_BUFFER_SIZE)) { + sizeOver = sizes - ((maxSize * 99) / 100); + minElements = elements / 100; + } else { + sizeOver = sizes - ((maxSize * 9) / 10); + minElements = elements / 10; + } + unsigned long pruneRows = elements * sizeOver / sizes; + if (pruneRows <= minElements) { + pruneRows = minElements; } prune(id, pruneRows); } From edc6f52a89a0c0795b8cf46474767c9cb8d506a2 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Wed, 19 Aug 2015 12:20:36 -0700 Subject: [PATCH 2/6] logd: prune 10% or 256 entries max (cherry pick from commit b39ed0c9925356c74a6347630b04d875288d803b) Bug: 22351810 Bug: 23327476 Change-Id: I902ba6b431d8b7cee2d65ee2f76e9f7c4f30b152 --- logd/LogBuffer.cpp | 18 +++++++----------- 1 file changed, 7 insertions(+), 11 deletions(-) diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index b9e8973ac..85f770a95 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -217,27 +217,23 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, return len; } -// If we're using more than 256K of memory for log entries, prune -// at least 10% of the log entries. For sizes above 1M, prune at -// least 1% of the log entries. +// Prune at most 10% of the log entries or 256, whichever is less. // // mLogElementsLock must be held when this function is called. void LogBuffer::maybePrune(log_id_t id) { size_t sizes = stats.sizes(id); unsigned long maxSize = log_buffer_size(id); if (sizes > maxSize) { - size_t sizeOver, minElements, elements = stats.elements(id); - if (maxSize > (4 * LOG_BUFFER_SIZE)) { - sizeOver = sizes - ((maxSize * 99) / 100); - minElements = elements / 100; - } else { - sizeOver = sizes - ((maxSize * 9) / 10); - minElements = elements / 10; - } + size_t sizeOver = sizes - ((maxSize * 9) / 10); + size_t elements = stats.elements(id); + size_t minElements = elements / 10; unsigned long pruneRows = elements * sizeOver / sizes; if (pruneRows <= minElements) { pruneRows = minElements; } + if (pruneRows > 256) { + pruneRows = 256; + } prune(id, pruneRows); } } From a68a5167bc098647bb8e8af1869c7020656d8388 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Wed, 19 Aug 2015 13:10:14 -0700 Subject: [PATCH 3/6] logd: logtimes switch to std::list (cherry pick from commit 98dca2d0b15f9a579efae8592dbb45059aad082e) Bug: 23350706 Change-Id: Icc60dd06119ea20a22610644ff880d5135363aba --- logd/FlushCommand.cpp | 2 +- logd/LogTimes.h | 8 +++++--- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/logd/FlushCommand.cpp b/logd/FlushCommand.cpp index d58492586..823a842fb 100644 --- a/logd/FlushCommand.cpp +++ b/logd/FlushCommand.cpp @@ -72,7 +72,7 @@ void FlushCommand::runSocketCommand(SocketClient *client) { return; } entry = new LogTimeEntry(mReader, client, mNonBlock, mTail, mLogMask, mPid, mStart); - times.push_back(entry); + times.push_front(entry); } client->incRef(); diff --git a/logd/LogTimes.h b/logd/LogTimes.h index 783bce675..39bcdd4e6 100644 --- a/logd/LogTimes.h +++ b/logd/LogTimes.h @@ -20,8 +20,10 @@ #include #include #include + +#include + #include -#include #include class LogReader; @@ -107,6 +109,6 @@ public: static int FilterSecondPass(const LogBufferElement *element, void *me); }; -typedef android::List LastLogTimes; +typedef std::list LastLogTimes; -#endif +#endif // _LOGD_LOG_TIMES_H__ From dc1c936139ab34e661bc82be3ceb81a5d5ffc9a1 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Wed, 19 Aug 2015 13:31:31 -0700 Subject: [PATCH 4/6] logd: white and black switch to std::list (cherry pick from commit e0ed16c6db5c443ecb5f9f7daca95a111fd1f582) Bug: 23350706 Change-Id: I981d9fa63a0d87eb309485cca93cfc44fc0506cc --- logd/LogWhiteBlackList.cpp | 28 +++++++++++----------------- logd/LogWhiteBlackList.h | 4 ++-- 2 files changed, 13 insertions(+), 19 deletions(-) diff --git a/logd/LogWhiteBlackList.cpp b/logd/LogWhiteBlackList.cpp index 277b3caf4..16dd6d2f0 100644 --- a/logd/LogWhiteBlackList.cpp +++ b/logd/LogWhiteBlackList.cpp @@ -50,18 +50,14 @@ void Prune::format(char **strp) { } PruneList::PruneList() : mWorstUidEnabled(true) { - mNaughty.clear(); - mNice.clear(); } PruneList::~PruneList() { PruneCollection::iterator it; for (it = mNice.begin(); it != mNice.end();) { - delete (*it); it = mNice.erase(it); } for (it = mNaughty.begin(); it != mNaughty.end();) { - delete (*it); it = mNaughty.erase(it); } } @@ -70,11 +66,9 @@ int PruneList::init(char *str) { mWorstUidEnabled = true; PruneCollection::iterator it; for (it = mNice.begin(); it != mNice.end();) { - delete (*it); it = mNice.erase(it); } for (it = mNaughty.begin(); it != mNaughty.end();) { - delete (*it); it = mNaughty.erase(it); } @@ -142,28 +136,28 @@ int PruneList::init(char *str) { // insert sequentially into list PruneCollection::iterator it = list->begin(); while (it != list->end()) { - Prune *p = *it; - int m = uid - p->mUid; + Prune &p = *it; + int m = uid - p.mUid; if (m == 0) { - if (p->mPid == p->pid_all) { + if (p.mPid == p.pid_all) { break; } - if ((pid == p->pid_all) && (p->mPid != p->pid_all)) { + if ((pid == p.pid_all) && (p.mPid != p.pid_all)) { it = list->erase(it); continue; } - m = pid - p->mPid; + m = pid - p.mPid; } if (m <= 0) { if (m < 0) { - list->insert(it, new Prune(uid,pid)); + list->insert(it, Prune(uid,pid)); } break; } ++it; } if (it == list->end()) { - list->push_back(new Prune(uid,pid)); + list->push_back(Prune(uid,pid)); } if (!*str) { break; @@ -193,7 +187,7 @@ void PruneList::format(char **strp) { for (it = mNice.begin(); it != mNice.end(); ++it) { char *a = NULL; - (*it)->format(&a); + (*it).format(&a); string.appendFormat(fmt, a); fmt = nice_format; @@ -205,7 +199,7 @@ void PruneList::format(char **strp) { fmt = naughty_format + (*fmt != ' '); for (it = mNaughty.begin(); it != mNaughty.end(); ++it) { char *a = NULL; - (*it)->format(&a); + (*it).format(&a); string.appendFormat(fmt, a); fmt = naughty_format; @@ -223,7 +217,7 @@ void PruneList::format(char **strp) { bool PruneList::naughty(LogBufferElement *element) { PruneCollection::iterator it; for (it = mNaughty.begin(); it != mNaughty.end(); ++it) { - if (!(*it)->cmp(element)) { + if (!(*it).cmp(element)) { return true; } } @@ -233,7 +227,7 @@ bool PruneList::naughty(LogBufferElement *element) { bool PruneList::nice(LogBufferElement *element) { PruneCollection::iterator it; for (it = mNice.begin(); it != mNice.end(); ++it) { - if (!(*it)->cmp(element)) { + if (!(*it).cmp(element)) { return true; } } diff --git a/logd/LogWhiteBlackList.h b/logd/LogWhiteBlackList.h index 5f60801aa..57cd03b98 100644 --- a/logd/LogWhiteBlackList.h +++ b/logd/LogWhiteBlackList.h @@ -19,7 +19,7 @@ #include -#include +#include #include @@ -47,7 +47,7 @@ public: void format(char **strp); }; -typedef android::List PruneCollection; +typedef std::list PruneCollection; class PruneList { PruneCollection mNaughty; From c2f7eee26b07498c0adf357fa8970716d8fac31f Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Wed, 19 Aug 2015 13:41:51 -0700 Subject: [PATCH 5/6] logd: log buffer switch to std::list (cherry pick from commit 94a89c42fe9521f5ac2d382a172c082ca421d6c3) Bug: 23350706 Bug: 23327476 Change-Id: Ib0530b9dd5842c6d05c84d7a66f2531c97461067 --- logd/LogBuffer.h | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h index a13fded8b..76571c67d 100644 --- a/logd/LogBuffer.h +++ b/logd/LogBuffer.h @@ -19,9 +19,10 @@ #include +#include + #include #include -#include #include @@ -30,7 +31,7 @@ #include "LogStatistics.h" #include "LogWhiteBlackList.h" -typedef android::List LogBufferElementCollection; +typedef std::list LogBufferElementCollection; class LogBuffer { LogBufferElementCollection mLogElements; From 0c5ab13a72f4ab76fe37b111550d8a64e70b5e7c Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Wed, 19 Aug 2015 17:06:11 -0700 Subject: [PATCH 6/6] logd: worst uid record watermark (cherry pick from commit c892ea3fa80dfd3d35c5a3b8bfdc73e7b85eaede) Hold on to last worst uid watermark and bypass a spike to O(n*n*x) (n=samples, x=number of spammers) wrt chatty trimming. Bug: 23327476 Change-Id: I9f21ce95e969b67e576417a760f75c4d86acf364 --- logd/LogBuffer.cpp | 19 ++++++++++++++++++- logd/LogBuffer.h | 5 +++++ 2 files changed, 23 insertions(+), 1 deletion(-) diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index 85f770a95..db3f26c72 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -240,7 +240,12 @@ void LogBuffer::maybePrune(log_id_t id) { LogBufferElementCollection::iterator LogBuffer::erase(LogBufferElementCollection::iterator it) { LogBufferElement *e = *it; + log_id_t id = e->getLogId(); + LogBufferIteratorMap::iterator f = mLastWorstUid[id].find(e->getUid()); + if ((f != mLastWorstUid[id].end()) && (it == f->second)) { + mLastWorstUid[id].erase(f); + } it = mLogElements.erase(it); stats.subtract(e); delete e; @@ -399,8 +404,17 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { bool kick = false; bool leading = true; + it = mLogElements.begin(); + if (worst != (uid_t) -1) { + LogBufferIteratorMap::iterator f = mLastWorstUid[id].find(worst); + if ((f != mLastWorstUid[id].end()) + && (f->second != mLogElements.end())) { + leading = false; + it = f->second; + } + } LogBufferElementLast last; - for(it = mLogElements.begin(); it != mLogElements.end();) { + while (it != mLogElements.end()) { LogBufferElement *e = *it; if (oldest && (oldest->mStart <= e->getSequence())) { @@ -450,8 +464,10 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { continue; } + // unmerged drop message if (dropped) { last.add(e); + mLastWorstUid[id][e->getUid()] = it; ++it; continue; } @@ -496,6 +512,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { delete e; } else { last.add(e); + mLastWorstUid[id][e->getUid()] = it; ++it; } } diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h index 76571c67d..e94598c82 100644 --- a/logd/LogBuffer.h +++ b/logd/LogBuffer.h @@ -40,6 +40,11 @@ class LogBuffer { LogStatistics stats; PruneList mPrune; + // watermark of any worst/chatty uid processing + typedef std::unordered_map + LogBufferIteratorMap; + LogBufferIteratorMap mLastWorstUid[LOG_ID_MAX]; unsigned long mMaxSize[LOG_ID_MAX];