Merge "logd: Add worst pid of system filter" (b5e82131) · Commits · e / os / android_system_core

logd/LogBuffer.cpp

+137 −76

Original line number	Diff line number	Diff line
		@@ -248,9 +248,9 @@ int LogBuffer::log(log_id_t log_id, log_time realtime,

		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 @@ int LogBuffer::log(log_id_t log_id, log_time realtime,
		end_set = true;
		}
		}
		t++;
		times++;
		}

		if (end_always
		@@ -307,20 +307,35 @@ void LogBuffer::maybePrune(log_id_t id) {

		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();

		{ // 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);
		}
		}

		LogBufferIteratorMap::iterator f = mLastWorstUid[id].find(e->getUid());
		if ((f != mLastWorstUid[id].end()) && (it == f->second)) {
		mLastWorstUid[id].erase(f);
		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 @@ class LogBufferElementKey {
		} __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 @@ class LogBufferElementLast {

		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		(entry->mTimeout.tv_sec \|\| entry->mTimeout.tv_nsec)))) {
		oldest = entry;
		}
		t++;
		times++;
		}

		LogBufferElementCollection::iterator it;
		@@ -467,14 +491,14 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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()) {
		{ // 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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		}
		}
		}

		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		// - 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())) {
		{ // 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 = f->second;
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		--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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {

		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 LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		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

logd/LogBuffer.h

+5 −0

Original line number	Diff line number	Diff line
		@@ -61,6 +61,11 @@ class LogBuffer {
		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];

logd/LogStatistics.cpp

+46 −1

Original line number	Diff line number	Diff line
		@@ -75,6 +75,9 @@ void LogStatistics::add(LogBufferElement *element) {
		}

		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 @@ void LogStatistics::subtract(LogBufferElement *element) {
		}

		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 @@ void LogStatistics::drop(LogBufferElement *element) {
		++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 @@ std::string UidEntry::format(const LogStatistics &stat, log_id_t id) const {
		}
		}

		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 {

logd/LogStatistics.h

+8 −0

Original line number	Diff line number	Diff line
		@@ -416,6 +416,10 @@ class LogStatistics {
		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 @@ public:
		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]; }

logd/LogWhiteBlackList.cpp

+19 −1

Original line number	Diff line number	Diff line
		@@ -66,6 +66,7 @@ PruneList::~PruneList() {

		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 @@ int PruneList::init(const char *str) {
		// 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 @@ int PruneList::init(const char *str) {
		}
		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 @@ std::string PruneList::format() {
		if (mWorstUidEnabled) {
		string = "~!";
		fmt = nice_format;
		if (mWorstPidOfSystemEnabled) {
		string += " ~1000/!";
		}
		}

		PruneCollection::iterator it;