Merge "logd: record multiple duplicate messages as chatty" (d0ee7393) · Commits · e / os / android_system_core

logd/LogAudit.cpp

+3 −1

Original line number	Diff line number	Diff line
		@@ -34,6 +34,7 @@
		#include "LogBuffer.h"
		#include "LogKlog.h"
		#include "LogReader.h"
		#include "LogUtils.h"

		#define KMSG_PRIORITY(PRI) \
		'<', \
		@@ -117,7 +118,8 @@ int LogAudit::logPrint(const char *fmt, ...) {
		if (avcl) {
		char *avcr = strstr(str, avc);

		skip = avcr && !strcmp(avcl + strlen(avc), avcr + strlen(avc));
		skip = avcr && !fastcmp<strcmp>(avcl + strlen(avc),
		avcr + strlen(avc));
		if (skip) {
		++count;
		free(last_str);

logd/LogBuffer.cpp

+104 −7

Original line number	Diff line number	Diff line
		@@ -33,6 +33,7 @@
		#include "LogBuffer.h"
		#include "LogKlog.h"
		#include "LogReader.h"
		#include "LogUtils.h"

		#ifndef __predict_false
		#define __predict_false(exp) __builtin_expect((exp) != 0, 0)
		@@ -110,9 +111,65 @@ LogBuffer::LogBuffer(LastLogTimes *times):
		mTimes(*times) {
		pthread_mutex_init(&mLogElementsLock, NULL);

		log_id_for_each(i) {
		lastLoggedElements[i] = NULL;
		droppedElements[i] = NULL;
		}

		init();
		}

		LogBuffer::~LogBuffer() {
		log_id_for_each(i) {
		delete lastLoggedElements[i];
		delete droppedElements[i];
		}
		}

		static bool identical(LogBufferElement* elem, LogBufferElement* last) {
		// is it mostly identical?
		// if (!elem) return false;
		unsigned short lenl = elem->getMsgLen();
		if (!lenl) return false;
		// if (!last) return false;
		unsigned short lenr = last->getMsgLen();
		if (!lenr) return false;
		// if (elem->getLogId() != last->getLogId()) return false;
		if (elem->getUid() != last->getUid()) return false;
		if (elem->getPid() != last->getPid()) return false;
		if (elem->getTid() != last->getTid()) return false;

		// last is more than a minute old, stop squashing identical messages
		if (elem->getRealTime().nsec() >
		(last->getRealTime().nsec() + 60 * NS_PER_SEC)) return false;

		// Identical message
		const char* msgl = elem->getMsg();
		const char* msgr = last->getMsg();
		if ((lenl == lenr) && !fastcmp<memcmp>(msgl, msgr, lenl)) return true;

		// audit message (except sequence number) identical?
		static const char avc[] = "): avc: ";

		if (last->isBinary()) {
		if (fastcmp<memcmp>(msgl, msgr,
		sizeof(android_log_event_string_t) -
		sizeof(int32_t))) return false;
		msgl += sizeof(android_log_event_string_t);
		lenl -= sizeof(android_log_event_string_t);
		msgr += sizeof(android_log_event_string_t);
		lenr -= sizeof(android_log_event_string_t);
		}
		const char *avcl = android::strnstr(msgl, lenl, avc);
		if (!avcl) return false;
		lenl -= avcl - msgl;
		const char *avcr = android::strnstr(msgr, lenr, avc);
		if (!avcr) return false;
		lenr -= avcr - msgr;
		if (lenl != lenr) return false;
		return !fastcmp<memcmp>(avcl + strlen(avc), avcr + strlen(avc), lenl);
		}

		int 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) {
		@@ -145,14 +202,57 @@ int LogBuffer::log(log_id_t log_id, log_time realtime,
		}

		pthread_mutex_lock(&mLogElementsLock);
		LogBufferElement* currentLast = lastLoggedElements[log_id];
		if (currentLast) {
		LogBufferElement *dropped = droppedElements[log_id];
		unsigned short count = dropped ? dropped->getDropped() : 0;
		if (identical(elem, currentLast)) {
		if (dropped) {
		if (count == USHRT_MAX) {
		log(dropped);
		count = 1;
		} else {
		delete dropped;
		++count;
		}
		}
		if (count) {
		stats.add(currentLast);
		stats.subtract(currentLast);
		currentLast->setDropped(count);
		}
		droppedElements[log_id] = currentLast;
		lastLoggedElements[log_id] = elem;
		pthread_mutex_unlock(&mLogElementsLock);
		return len;
		}
		if (dropped) {
		log(dropped);
		droppedElements[log_id] = NULL;
		}
		if (count) {
		log(currentLast);
		} else {
		delete currentLast;
		}
		}
		lastLoggedElements[log_id] = new LogBufferElement(*elem);

		log(elem);
		pthread_mutex_unlock(&mLogElementsLock);

		return len;
		}

		// assumes mLogElementsLock held, owns elem, will look after garbage collection
		void LogBuffer::log(LogBufferElement* elem) {
		// 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 (last != mLogElements.begin()) {
		--it;
		if ((*it)->getRealTime() <= realtime) {
		if ((*it)->getRealTime() <= elem->getRealTime()) {
		break;
		}
		last = it;
		@@ -194,10 +294,7 @@ int LogBuffer::log(log_id_t log_id, log_time realtime,
		}

		stats.add(elem);
		maybePrune(log_id);
		pthread_mutex_unlock(&mLogElementsLock);

		return len;
		maybePrune(elem->getLogId());
		}

		// Prune at most 10% of the log entries or maxPrune, whichever is less.

logd/LogBuffer.h

+5 −0

Original line number	Diff line number	Diff line
		@@ -99,10 +99,15 @@ class LogBuffer {

		bool monotonic;

		LogBufferElement* lastLoggedElements[LOG_ID_MAX];
		LogBufferElement* droppedElements[LOG_ID_MAX];
		void log(LogBufferElement* elem);

		public:
		LastLogTimes &mTimes;

		explicit LogBuffer(LastLogTimes *times);
		~LogBuffer();
		void init();
		bool isMonotonic() { return monotonic; }

logd/LogBufferElement.cpp

+13 −2

Original line number	Diff line number	Diff line
		@@ -50,6 +50,19 @@ LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime,
		0;
		}

		LogBufferElement::LogBufferElement(const LogBufferElement &elem) :
		mTag(elem.mTag),
		mUid(elem.mUid),
		mPid(elem.mPid),
		mTid(elem.mTid),
		mSequence(elem.mSequence),
		mRealTime(elem.mRealTime),
		mMsgLen(elem.mMsgLen),
		mLogId(elem.mLogId) {
		mMsg = new char[mMsgLen];
		memcpy(mMsg, elem.mMsg, mMsgLen);
		}

		LogBufferElement::~LogBufferElement() {
		delete [] mMsg;
		}
		@@ -157,8 +170,6 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer,
		mDropped, (mDropped > 1) ? "s" : "");

		size_t hdrLen;
		// LOG_ID_SECURITY not strictly needed since spam filter not activated,
		// but required for accuracy.
		if (isBinary()) {
		hdrLen = sizeof(android_log_event_string_t);
		} else {

logd/LogBufferElement.h

+2 −0

Original line number	Diff line number	Diff line
		@@ -59,6 +59,7 @@ public:
		LogBufferElement(log_id_t log_id, log_time realtime,
		uid_t uid, pid_t pid, pid_t tid,
		const char *msg, unsigned short len);
		LogBufferElement(const LogBufferElement &elem);
		virtual ~LogBufferElement();

		bool isBinary(void) const {
		@@ -79,6 +80,7 @@ public:
		return mDropped = value;
		}
		unsigned short getMsgLen() const { return mMsg ? mMsgLen : 0; }
		const char* getMsg() const { return mMsg; }
		uint64_t getSequence(void) const { return mSequence; }
		static uint64_t getCurrentSequence(void) { return sequence.load(memory_order_relaxed); }
		log_time getRealTime(void) const { return mRealTime; }