logd: Add worst pid of system filter
- Add a new statistic that reports per pid and log_id for AID_SYSTEM
- Add a new pruning filter ~1000/! boolean
- Use this new statistic to prune on worst pid within AID_SYSTEM
Bug: 26029733
Bug: 21615139
Bug: 22855208
Change-Id: Iab5dd28f807dcf03d276372853883f3b6afa8294
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 110395c..ec32393 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -248,9 +248,9 @@
LogTimeEntry::lock();
- LastLogTimes::iterator t = mTimes.begin();
- while(t != mTimes.end()) {
- LogTimeEntry *entry = (*t);
+ LastLogTimes::iterator times = mTimes.begin();
+ while(times != mTimes.end()) {
+ LogTimeEntry *entry = (*times);
if (entry->owned_Locked()) {
if (!entry->mNonBlock) {
end_always = true;
@@ -261,7 +261,7 @@
end_set = true;
}
}
- t++;
+ times++;
}
if (end_always
@@ -307,20 +307,35 @@
LogBufferElementCollection::iterator LogBuffer::erase(
LogBufferElementCollection::iterator it, bool coalesce) {
- LogBufferElement *e = *it;
- log_id_t id = e->getLogId();
+ LogBufferElement *element = *it;
+ log_id_t id = element->getLogId();
- LogBufferIteratorMap::iterator f = mLastWorstUid[id].find(e->getUid());
- if ((f != mLastWorstUid[id].end()) && (it == f->second)) {
- mLastWorstUid[id].erase(f);
+ { // start of scope for uid found iterator
+ LogBufferIteratorMap::iterator found =
+ mLastWorstUid[id].find(element->getUid());
+ if ((found != mLastWorstUid[id].end())
+ && (it == found->second)) {
+ mLastWorstUid[id].erase(found);
+ }
}
+
+ if (element->getUid() == AID_SYSTEM) {
+ // start of scope for pid found iterator
+ LogBufferPidIteratorMap::iterator found =
+ mLastWorstPidOfSystem[id].find(element->getPid());
+ if ((found != mLastWorstPidOfSystem[id].end())
+ && (it == found->second)) {
+ mLastWorstPidOfSystem[id].erase(found);
+ }
+ }
+
it = mLogElements.erase(it);
if (coalesce) {
- stats.erase(e);
+ stats.erase(element);
} else {
- stats.subtract(e);
+ stats.subtract(element);
}
- delete e;
+ delete element;
return it;
}
@@ -340,8 +355,13 @@
} __packed;
public:
- LogBufferElementKey(uid_t u, pid_t p, pid_t t):uid(u),pid(p),tid(t),padding(0) { }
- LogBufferElementKey(uint64_t k):value(k) { }
+ LogBufferElementKey(uid_t uid, pid_t pid, pid_t tid):
+ uid(uid),
+ pid(pid),
+ tid(tid),
+ padding(0) {
+ }
+ LogBufferElementKey(uint64_t key):value(key) { }
uint64_t getKey() { return value; }
};
@@ -353,38 +373,42 @@
public:
- bool coalesce(LogBufferElement *e, unsigned short dropped) {
- LogBufferElementKey key(e->getUid(), e->getPid(), e->getTid());
+ bool coalesce(LogBufferElement *element, unsigned short dropped) {
+ LogBufferElementKey key(element->getUid(),
+ element->getPid(),
+ element->getTid());
LogBufferElementMap::iterator it = map.find(key.getKey());
if (it != map.end()) {
- LogBufferElement *l = it->second;
- unsigned short d = l->getDropped();
- if ((dropped + d) > USHRT_MAX) {
+ LogBufferElement *found = it->second;
+ unsigned short moreDropped = found->getDropped();
+ if ((dropped + moreDropped) > USHRT_MAX) {
map.erase(it);
} else {
- l->setDropped(dropped + d);
+ found->setDropped(dropped + moreDropped);
return true;
}
}
return false;
}
- void add(LogBufferElement *e) {
- LogBufferElementKey key(e->getUid(), e->getPid(), e->getTid());
- map[key.getKey()] = e;
+ void add(LogBufferElement *element) {
+ LogBufferElementKey key(element->getUid(),
+ element->getPid(),
+ element->getTid());
+ map[key.getKey()] = element;
}
inline void clear() {
map.clear();
}
- void clear(LogBufferElement *e) {
- uint64_t current = e->getRealTime().nsec()
+ void clear(LogBufferElement *element) {
+ uint64_t current = element->getRealTime().nsec()
- (EXPIRE_RATELIMIT * NS_PER_SEC);
for(LogBufferElementMap::iterator it = map.begin(); it != map.end();) {
- LogBufferElement *l = it->second;
- if ((l->getDropped() >= EXPIRE_THRESHOLD)
- && (current > l->getRealTime().nsec())) {
+ LogBufferElement *mapElement = it->second;
+ if ((mapElement->getDropped() >= EXPIRE_THRESHOLD)
+ && (current > mapElement->getRealTime().nsec())) {
it = map.erase(it);
} else {
++it;
@@ -449,9 +473,9 @@
LogTimeEntry::lock();
// Region locked?
- LastLogTimes::iterator t = mTimes.begin();
- while(t != mTimes.end()) {
- LogTimeEntry *entry = (*t);
+ LastLogTimes::iterator times = mTimes.begin();
+ while(times != mTimes.end()) {
+ LogTimeEntry *entry = (*times);
if (entry->owned_Locked() && entry->isWatching(id)
&& (!oldest ||
(oldest->mStart > entry->mStart) ||
@@ -459,7 +483,7 @@
(entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec)))) {
oldest = entry;
}
- t++;
+ times++;
}
LogBufferElementCollection::iterator it;
@@ -467,14 +491,14 @@
if (caller_uid != AID_ROOT) {
// Only here if clearAll condition (pruneRows == ULONG_MAX)
for(it = mLogElements.begin(); it != mLogElements.end();) {
- LogBufferElement *e = *it;
+ LogBufferElement *element = *it;
- if ((e->getLogId() != id) || (e->getUid() != caller_uid)) {
+ if ((element->getLogId() != id) || (element->getUid() != caller_uid)) {
++it;
continue;
}
- if (oldest && (oldest->mStart <= e->getSequence())) {
+ if (oldest && (oldest->mStart <= element->getSequence())) {
busy = true;
if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
oldest->triggerReader_Locked();
@@ -491,20 +515,21 @@
return busy;
}
- // prune by worst offender by uid
+ // prune by worst offenders; by blacklist, UID, and by PID of system UID
bool hasBlacklist = (id != LOG_ID_SECURITY) && mPrune.naughty();
while (!clearAll && (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;
+ pid_t worstPid = 0; // POSIX guarantees PID != 0
if (worstUidEnabledForLogid(id) && mPrune.worstUidEnabled()) {
- std::unique_ptr<const UidEntry *[]> sorted = stats.sort(
- AID_ROOT, (pid_t)0, 2, id);
+ { // begin scope for UID sorted list
+ std::unique_ptr<const UidEntry *[]> sorted = stats.sort(
+ AID_ROOT, (pid_t)0, 2, id);
- if (sorted.get()) {
- if (sorted[0] && sorted[1]) {
+ if (sorted.get() && sorted[0] && sorted[1]) {
worst_sizes = sorted[0]->getSizes();
// Calculate threshold as 12.5% of available storage
size_t threshold = log_buffer_size(id) / 8;
@@ -520,6 +545,18 @@
}
}
}
+
+ if ((worst == AID_SYSTEM) && mPrune.worstPidOfSystemEnabled()) {
+ // begin scope of PID sorted list
+ std::unique_ptr<const PidEntry *[]> sorted = stats.sort(
+ worst, (pid_t)0, 2, id, worst);
+ if (sorted.get() && sorted[0] && sorted[1]) {
+ worstPid = sorted[0]->getKey();
+ second_worst_sizes = worst_sizes
+ - sorted[0]->getSizes()
+ + sorted[1]->getSizes();
+ }
+ }
}
// skip if we have neither worst nor naughty filters
@@ -536,11 +573,23 @@
// - check age-out of preserved logs
bool gc = pruneRows <= 1;
if (!gc && (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;
+ { // begin scope for uid worst found iterator
+ LogBufferIteratorMap::iterator found = mLastWorstUid[id].find(worst);
+ if ((found != mLastWorstUid[id].end())
+ && (found->second != mLogElements.end())) {
+ leading = false;
+ it = found->second;
+ }
+ }
+ if (worstPid) {
+ // begin scope for pid worst found iterator
+ LogBufferPidIteratorMap::iterator found
+ = mLastWorstPidOfSystem[id].find(worstPid);
+ if ((found != mLastWorstPidOfSystem[id].end())
+ && (found->second != mLogElements.end())) {
+ leading = false;
+ it = found->second;
+ }
}
}
static const timespec too_old = {
@@ -551,9 +600,9 @@
--lastt;
LogBufferElementLast last;
while (it != mLogElements.end()) {
- LogBufferElement *e = *it;
+ LogBufferElement *element = *it;
- if (oldest && (oldest->mStart <= e->getSequence())) {
+ if (oldest && (oldest->mStart <= element->getSequence())) {
busy = true;
if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
oldest->triggerReader_Locked();
@@ -561,12 +610,12 @@
break;
}
- if (e->getLogId() != id) {
+ if (element->getLogId() != id) {
++it;
continue;
}
- unsigned short dropped = e->getDropped();
+ unsigned short dropped = element->getDropped();
// remove any leading drops
if (leading && dropped) {
@@ -574,13 +623,13 @@
continue;
}
- if (dropped && last.coalesce(e, dropped)) {
+ if (dropped && last.coalesce(element, dropped)) {
it = erase(it, true);
continue;
}
- if (hasBlacklist && mPrune.naughty(e)) {
- last.clear(e);
+ if (hasBlacklist && mPrune.naughty(element)) {
+ last.clear(element);
it = erase(it);
if (dropped) {
continue;
@@ -591,35 +640,42 @@
break;
}
- if (e->getUid() == worst) {
+ if (element->getUid() == worst) {
kick = true;
if (worst_sizes < second_worst_sizes) {
break;
}
- worst_sizes -= e->getMsgLen();
+ worst_sizes -= element->getMsgLen();
}
continue;
}
- if ((e->getRealTime() < ((*lastt)->getRealTime() - too_old))
- || (e->getRealTime() > (*lastt)->getRealTime())) {
+ if ((element->getRealTime() < ((*lastt)->getRealTime() - too_old))
+ || (element->getRealTime() > (*lastt)->getRealTime())) {
break;
}
if (dropped) {
- last.add(e);
- if ((!gc && (e->getUid() == worst))
- || (mLastWorstUid[id].find(e->getUid())
+ last.add(element);
+ if (worstPid
+ && ((!gc && (element->getPid() == worstPid))
+ || (mLastWorstPidOfSystem[id].find(element->getPid())
+ == mLastWorstPidOfSystem[id].end()))) {
+ mLastWorstPidOfSystem[id][element->getUid()] = it;
+ }
+ if ((!gc && !worstPid && (element->getUid() == worst))
+ || (mLastWorstUid[id].find(element->getUid())
== mLastWorstUid[id].end())) {
- mLastWorstUid[id][e->getUid()] = it;
+ mLastWorstUid[id][element->getUid()] = it;
}
++it;
continue;
}
- if (e->getUid() != worst) {
+ if ((element->getUid() != worst)
+ || (worstPid && (element->getPid() != worstPid))) {
leading = false;
- last.clear(e);
+ last.clear(element);
++it;
continue;
}
@@ -631,19 +687,24 @@
kick = true;
- unsigned short len = e->getMsgLen();
+ unsigned short len = element->getMsgLen();
// do not create any leading drops
if (leading) {
it = erase(it);
} else {
- stats.drop(e);
- e->setDropped(1);
- if (last.coalesce(e, 1)) {
+ stats.drop(element);
+ element->setDropped(1);
+ if (last.coalesce(element, 1)) {
it = erase(it, true);
} else {
- last.add(e);
- if (!gc || (mLastWorstUid[id].find(worst)
+ last.add(element);
+ if (worstPid && (!gc
+ || (mLastWorstPidOfSystem[id].find(worstPid)
+ == mLastWorstPidOfSystem[id].end()))) {
+ mLastWorstPidOfSystem[id][worstPid] = it;
+ }
+ if ((!gc && !worstPid) || (mLastWorstUid[id].find(worst)
== mLastWorstUid[id].end())) {
mLastWorstUid[id][worst] = it;
}
@@ -666,16 +727,15 @@
bool hasWhitelist = (id != LOG_ID_SECURITY) && mPrune.nice() && !clearAll;
it = mLogElements.begin();
while((pruneRows > 0) && (it != mLogElements.end())) {
- LogBufferElement *e = *it;
+ LogBufferElement *element = *it;
- if (e->getLogId() != id) {
+ if (element->getLogId() != id) {
it++;
continue;
}
- if (oldest && (oldest->mStart <= e->getSequence())) {
+ if (oldest && (oldest->mStart <= element->getSequence())) {
busy = true;
-
if (whitelist) {
break;
}
@@ -691,7 +751,8 @@
break;
}
- if (hasWhitelist && !e->getDropped() && mPrune.nice(e)) { // WhiteListed
+ if (hasWhitelist && !element->getDropped() && mPrune.nice(element)) {
+ // WhiteListed
whitelist = true;
it++;
continue;
@@ -705,14 +766,14 @@
if (whitelist && (pruneRows > 0)) {
it = mLogElements.begin();
while((it != mLogElements.end()) && (pruneRows > 0)) {
- LogBufferElement *e = *it;
+ LogBufferElement *element = *it;
- if (e->getLogId() != id) {
+ if (element->getLogId() != id) {
++it;
continue;
}
- if (oldest && (oldest->mStart <= e->getSequence())) {
+ if (oldest && (oldest->mStart <= element->getSequence())) {
busy = true;
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h
index c1614e8..0243749 100644
--- a/logd/LogBuffer.h
+++ b/logd/LogBuffer.h
@@ -61,6 +61,11 @@
LogBufferElementCollection::iterator>
LogBufferIteratorMap;
LogBufferIteratorMap mLastWorstUid[LOG_ID_MAX];
+ // watermark of any worst/chatty pid of system processing
+ typedef std::unordered_map<pid_t,
+ LogBufferElementCollection::iterator>
+ LogBufferPidIteratorMap;
+ LogBufferPidIteratorMap mLastWorstPidOfSystem[LOG_ID_MAX];
unsigned long mMaxSize[LOG_ID_MAX];
diff --git a/logd/LogStatistics.cpp b/logd/LogStatistics.cpp
index afaefc2..2b02bc1 100644
--- a/logd/LogStatistics.cpp
+++ b/logd/LogStatistics.cpp
@@ -75,6 +75,9 @@
}
uidTable[log_id].add(element->getUid(), element);
+ if (element->getUid() == AID_SYSTEM) {
+ pidSystemTable[log_id].add(element->getPid(), element);
+ }
if (!enable) {
return;
@@ -107,6 +110,9 @@
}
uidTable[log_id].subtract(element->getUid(), element);
+ if (element->getUid() == AID_SYSTEM) {
+ pidSystemTable[log_id].subtract(element->getPid(), element);
+ }
if (!enable) {
return;
@@ -134,6 +140,9 @@
++mDroppedElements[log_id];
uidTable[log_id].drop(element->getUid(), element);
+ if (element->getUid() == AID_SYSTEM) {
+ pidSystemTable[log_id].drop(element->getPid(), element);
+ }
if (!enable) {
return;
@@ -273,7 +282,43 @@
}
}
- return formatLine(name, size, pruned);
+ std::string output = formatLine(name, size, pruned);
+
+ if (uid != AID_SYSTEM) {
+ return output;
+ }
+
+ static const size_t maximum_sorted_entries = 32;
+ std::unique_ptr<const PidEntry *[]> sorted
+ = stat.pidSystemTable[id].sort(uid, (pid_t)0, maximum_sorted_entries);
+
+ if (!sorted.get()) {
+ return output;
+ }
+ std::string byPid;
+ size_t index;
+ bool hasDropped = false;
+ for (index = 0; index < maximum_sorted_entries; ++index) {
+ const PidEntry *entry = sorted[index];
+ if (!entry) {
+ break;
+ }
+ if (entry->getSizes() <= (getSizes() / 100)) {
+ break;
+ }
+ if (entry->getDropped()) {
+ hasDropped = true;
+ }
+ byPid += entry->format(stat, id);
+ }
+ if (index > 1) { // print this only if interesting
+ std::string ditto("\" ");
+ output += formatLine(std::string(" PID/UID COMMAND LINE"),
+ ditto, hasDropped ? ditto : std::string(""));
+ output += byPid;
+ }
+
+ return output;
}
std::string PidEntry::formatHeader(const std::string &name, log_id_t /* id */) const {
diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h
index 6d999d2..6f7d264 100644
--- a/logd/LogStatistics.h
+++ b/logd/LogStatistics.h
@@ -416,6 +416,10 @@
typedef LogHashtable<uid_t, UidEntry> uidTable_t;
uidTable_t uidTable[LOG_ID_MAX];
+ // pid of system to size list
+ typedef LogHashtable<pid_t, PidEntry> pidSystemTable_t;
+ pidSystemTable_t pidSystemTable[LOG_ID_MAX];
+
// pid to uid list
typedef LogHashtable<pid_t, PidEntry> pidTable_t;
pidTable_t pidTable;
@@ -451,6 +455,10 @@
size_t len, log_id id) {
return uidTable[id].sort(uid, pid, len);
}
+ std::unique_ptr<const PidEntry *[]> sort(uid_t uid, pid_t pid,
+ size_t len, log_id id, uid_t) {
+ return pidSystemTable[id].sort(uid, pid, len);
+ }
// fast track current value by id only
size_t sizes(log_id_t id) const { return mSizes[id]; }
diff --git a/logd/LogWhiteBlackList.cpp b/logd/LogWhiteBlackList.cpp
index 29e637e..ae933b5 100644
--- a/logd/LogWhiteBlackList.cpp
+++ b/logd/LogWhiteBlackList.cpp
@@ -66,6 +66,7 @@
int PruneList::init(const char *str) {
mWorstUidEnabled = true;
+ mWorstPidOfSystemEnabled = true;
PruneCollection::iterator it;
for (it = mNice.begin(); it != mNice.end();) {
it = mNice.erase(it);
@@ -103,13 +104,14 @@
// default here means take internal default.
if (filter == _default) {
// See README.property for description of filter format
- filter = "~!";
+ filter = "~! ~1000/!";
}
if (filter == _disable) {
filter = "";
}
mWorstUidEnabled = false;
+ mWorstPidOfSystemEnabled = false;
for(str = filter.c_str(); *str; ++str) {
if (isspace(*str)) {
@@ -131,6 +133,19 @@
}
continue;
}
+ // special case, translated to worst PID of System at priority
+ static const char worstPid[] = "1000/!";
+ if (!strncmp(str, worstPid, sizeof(worstPid) - 1)) {
+ mWorstPidOfSystemEnabled = true;
+ str += sizeof(worstPid) - 1;
+ if (!*str) {
+ break;
+ }
+ if (!isspace(*str)) {
+ return 1;
+ }
+ continue;
+ }
if (!*str) {
return 1;
}
@@ -209,6 +224,9 @@
if (mWorstUidEnabled) {
string = "~!";
fmt = nice_format;
+ if (mWorstPidOfSystemEnabled) {
+ string += " ~1000/!";
+ }
}
PruneCollection::iterator it;
diff --git a/logd/LogWhiteBlackList.h b/logd/LogWhiteBlackList.h
index 6f17402..8b8e02f 100644
--- a/logd/LogWhiteBlackList.h
+++ b/logd/LogWhiteBlackList.h
@@ -53,6 +53,7 @@
PruneCollection mNaughty;
PruneCollection mNice;
bool mWorstUidEnabled;
+ bool mWorstPidOfSystemEnabled;
public:
PruneList();
@@ -65,6 +66,7 @@
bool nice(LogBufferElement *element);
bool nice(void) { return !mNice.empty(); }
bool worstUidEnabled() const { return mWorstUidEnabled; }
+ bool worstPidOfSystemEnabled() const { return mWorstPidOfSystemEnabled; }
std::string format();
};
diff --git a/logd/README.property b/logd/README.property
index 019bd40..75d9eb0 100644
--- a/logd/README.property
+++ b/logd/README.property
@@ -23,9 +23,11 @@
of 256K.
persist.logd.filter string Pruning filter to optimize content.
At runtime use: logcat -P "<string>"
-ro.logd.filter string "~!" default for persist.logd.filter.
+ro.logd.filter string "~! ~1000/!" default for persist.logd.filter.
This default means to prune the
- oldest entries of chattiest UID.
+ oldest entries of chattiest UID, and
+ the chattiest PID of system
+ (1000, or AID_SYSTEM).
persist.logd.timestamp string ro The recording timestamp source.
"m[onotonic]" is the only supported
key character, otherwise realtime.
@@ -52,4 +54,6 @@
such as main, system, ... override global default.
- Pruning filter is of form of a space-separated list of [~][UID][/PID]
references, where '~' prefix means to blacklist otherwise whitelist. For
- blacklisting, UID may be a '!' to instead reference the chattiest client.
+ blacklisting, UID or PID may be a '!' to instead reference the chattiest
+ client, with the restriction that the PID must be in the UID group 1000
+ (system or AID_SYSTEM).