Merge changes If1a62a90,Ibce79cf1,Ia2bbf01a,I1763be56,I56762747, ... am: 56cd920ff8 (31ef8001) · Commits · e / os / android_system_core

logd/FlushCommand.cpp

+2 −12

Original line number	Diff line number	Diff line
		@@ -49,19 +49,9 @@ void FlushCommand::runSocketCommand(SocketClient* client) {
		return;
		}
		if (entry->mTimeout.tv_sec \|\| entry->mTimeout.tv_nsec) {
		if (mReader.logbuf().isMonotonic()) {
		LogTimeEntry::unlock();
		return;
		}
		// If the user changes the time in a gross manner that
		// invalidates the timeout, fall through and trigger.
		log_time now(CLOCK_REALTIME);
		if (((entry->mEnd + entry->mTimeout) > now) &&
		(now > entry->mEnd)) {
		LogTimeEntry::unlock();
		return;
		}
		}
		entry->triggerReader_Locked();
		LogTimeEntry::unlock();
		return;

logd/FlushCommand.h

+1 −1

Original line number	Diff line number	Diff line
		@@ -16,7 +16,7 @@
		#ifndef _FLUSH_COMMAND_H
		#define _FLUSH_COMMAND_H

		#include <private/android_logger.h>
		#include <android/log.h>
		#include <sysutils/SocketClientCommand.h>

		class LogBufferElement;

logd/LogBuffer.cpp

+24 −101

Original line number	Diff line number	Diff line
		@@ -27,6 +27,7 @@
		#include <unistd.h>

		#include <unordered_map>
		#include <utility>

		#include <cutils/properties.h>
		#include <private/android_logger.h>
		@@ -43,8 +44,6 @@
		// Default
		#define log_buffer_size(id) mMaxSize[id]

		const log_time LogBuffer::pruneMargin(3, 0);

		void LogBuffer::init() {
		log_id_for_each(i) {
		mLastSet[i] = false;
		@@ -390,59 +389,7 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,

		// assumes LogBuffer::wrlock() held, owns elem, look after garbage collection
		void LogBuffer::log(LogBufferElement* elem) {
		// cap on how far back we will sort in-place, otherwise append
		static uint32_t too_far_back = 5; // five seconds
		// 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;
		if (__predict_true(it != mLogElements.begin())) --it;
		if (__predict_false(it == mLogElements.begin()) \|\|
		__predict_true((*it)->getRealTime() <= elem->getRealTime()) \|\|
		__predict_false((((*it)->getRealTime().tv_sec - too_far_back) >
		elem->getRealTime().tv_sec) &&
		(elem->getLogId() != LOG_ID_KERNEL) &&
		((*it)->getLogId() != LOG_ID_KERNEL))) {
		mLogElements.push_back(elem);
		} else {
		log_time end(log_time::EPOCH);
		bool end_set = false;
		bool end_always = false;

		LogTimeEntry::rdlock();

		LastLogTimes::iterator times = mTimes.begin();
		while (times != mTimes.end()) {
		LogTimeEntry* entry = times->get();
		if (!entry->mNonBlock) {
		end_always = true;
		break;
		}
		// it passing mEnd is blocked by the following checks.
		if (!end_set \|\| (end <= entry->mEnd)) {
		end = entry->mEnd;
		end_set = true;
		}
		times++;
		}

		if (end_always \|\| (end_set && (end > (*it)->getRealTime()))) {
		mLogElements.push_back(elem);
		} else {
		// should be short as timestamps are localized near end()
		do {
		last = it;
		if (__predict_false(it == mLogElements.begin())) {
		break;
		}
		--it;
		} while (((*it)->getRealTime() > elem->getRealTime()) &&
		(!end_set \|\| (end <= (*it)->getRealTime())));
		mLogElements.insert(last, elem);
		}
		LogTimeEntry::unlock();
		}

		stats.add(elem);
		maybePrune(elem->getLogId());
		}
		@@ -614,12 +561,11 @@ class LogBufferElementLast {
		}

		void clear(LogBufferElement* element) {
		log_time current =
		element->getRealTime() - log_time(EXPIRE_RATELIMIT, 0);
		uint64_t current = element->getRealTime().nsec() - (EXPIRE_RATELIMIT * NS_PER_SEC);
		for (LogBufferElementMap::iterator it = map.begin(); it != map.end();) {
		LogBufferElement* mapElement = it->second;
		if ((mapElement->getDropped() >= EXPIRE_THRESHOLD) &&
		(current > mapElement->getRealTime())) {
		if (mapElement->getDropped() >= EXPIRE_THRESHOLD &&
		current > mapElement->getRealTime().nsec()) {
		it = map.erase(it);
		} else {
		++it;
		@@ -628,16 +574,6 @@ class LogBufferElementLast {
		}
		};

		// Determine if watermark is within pruneMargin + 1s from the end of the list,
		// the caller will use this result to set an internal busy flag indicating
		// the prune operation could not be completed because a reader is blocking
		// the request.
		bool LogBuffer::isBusy(log_time watermark) {
		LogBufferElementCollection::iterator ei = mLogElements.end();
		--ei;
		return watermark < ((*ei)->getRealTime() - pruneMargin - log_time(1, 0));
		}

		// If the selected reader is blocking our pruning progress, decide on
		// what kind of mitigation is necessary to unblock the situation.
		void LogBuffer::kickMe(LogTimeEntry* me, log_id_t id, unsigned long pruneRows) {
		@@ -726,8 +662,6 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		}
		times++;
		}
		log_time watermark(log_time::tv_sec_max, log_time::tv_nsec_max);
		if (oldest) watermark = oldest->mStart - pruneMargin;

		LogBufferElementCollection::iterator it;

		@@ -749,9 +683,9 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		mLastSet[id] = true;
		}

		if (oldest && (watermark <= element->getRealTime())) {
		busy = isBusy(watermark);
		if (busy) kickMe(oldest, id, pruneRows);
		if (oldest && oldest->mStart <= element->getSequence()) {
		busy = true;
		kickMe(oldest, id, pruneRows);
		break;
		}

		@@ -837,8 +771,8 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		while (it != mLogElements.end()) {
		LogBufferElement* element = *it;

		if (oldest && (watermark <= element->getRealTime())) {
		busy = isBusy(watermark);
		if (oldest && oldest->mStart <= element->getSequence()) {
		busy = true;
		// Do not let chatty eliding trigger any reader mitigation
		break;
		}
		@@ -989,9 +923,9 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		mLastSet[id] = true;
		}

		if (oldest && (watermark <= element->getRealTime())) {
		busy = isBusy(watermark);
		if (!whitelist && busy) kickMe(oldest, id, pruneRows);
		if (oldest && oldest->mStart <= element->getSequence()) {
		busy = true;
		if (!whitelist) kickMe(oldest, id, pruneRows);
		break;
		}

		@@ -1022,9 +956,9 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
		mLastSet[id] = true;
		}

		if (oldest && (watermark <= element->getRealTime())) {
		busy = isBusy(watermark);
		if (busy) kickMe(oldest, id, pruneRows);
		if (oldest && oldest->mStart <= element->getSequence()) {
		busy = true;
		kickMe(oldest, id, pruneRows);
		break;
		}

		@@ -1111,43 +1045,32 @@ unsigned long LogBuffer::getSize(log_id_t id) {
		return retval;
		}

		log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start,
		pid_t* lastTid, bool privileged, bool security,
		int (filter)(const LogBufferElement element,
		void* arg),
		void* arg) {
		uint64_t LogBuffer::flushTo(SocketClient* reader, uint64_t start, pid_t* lastTid, bool privileged,
		bool security,
		int (filter)(const LogBufferElement element, void* arg), void* arg) {
		LogBufferElementCollection::iterator it;
		uid_t uid = reader->getUid();

		rdlock();

		if (start == log_time::EPOCH) {
		if (start <= 1) {
		// client wants to start from the beginning
		it = mLogElements.begin();
		} else {
		// Cap to 300 iterations we look back for out-of-order entries.
		size_t count = 300;

		// Client wants to start from some specified time. Chances are
		// we are better off starting from the end of the time sorted list.
		LogBufferElementCollection::iterator last;
		for (last = it = mLogElements.end(); it != mLogElements.begin();
		for (it = mLogElements.end(); it != mLogElements.begin();
		/* do nothing */) {
		--it;
		LogBufferElement* element = *it;
		if (element->getRealTime() > start) {
		last = it;
		} else if (element->getRealTime() == start) {
		last = ++it;
		break;
		} else if (!--count) {
		if (element->getSequence() <= start) {
		it++;
		break;
		}
		}
		it = last;
		}

		log_time curr = start;
		uint64_t curr = start;

		LogBufferElement* lastElement = nullptr; // iterator corruption paranoia
		static const size_t maxSkip = 4194304; // maximum entries to skip

logd/LogBuffer.h

+2 −5

Original line number	Diff line number	Diff line
		@@ -118,11 +118,10 @@ class LogBuffer {
		// lastTid is an optional context to help detect if the last previous
		// valid message was from the same source so we can differentiate chatty
		// filter types (identical or expired)
		log_time flushTo(SocketClient* writer, const log_time& start,
		uint64_t flushTo(SocketClient* writer, uint64_t start,
		pid_t* lastTid, // &lastTid[LOG_ID_MAX] or nullptr
		bool privileged, bool security,
		int (filter)(const LogBufferElement element,
		void* arg) = nullptr,
		int (filter)(const LogBufferElement element, void* arg) = nullptr,
		void* arg = nullptr);

		bool clear(log_id_t id, uid_t uid = AID_ROOT);
		@@ -175,10 +174,8 @@ class LogBuffer {
		private:
		static constexpr size_t minPrune = 4;
		static constexpr size_t maxPrune = 256;
		static const log_time pruneMargin;

		void maybePrune(log_id_t id);
		bool isBusy(log_time watermark);
		void kickMe(LogTimeEntry* me, log_id_t id, unsigned long pruneRows);

		bool prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT);

logd/LogBufferElement.cpp

+8 −9

Original line number	Diff line number	Diff line
		@@ -30,15 +30,15 @@
		#include "LogReader.h"
		#include "LogUtils.h"

		const log_time LogBufferElement::FLUSH_ERROR((uint32_t)-1, (uint32_t)-1);
		const uint64_t LogBufferElement::FLUSH_ERROR(0);
		atomic_int_fast64_t LogBufferElement::sequence(1);

		LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime,
		uid_t uid, pid_t pid, pid_t tid,
		const char* msg, uint16_t len)
		LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
		pid_t tid, const char* msg, uint16_t len)
		: mUid(uid),
		mPid(pid),
		mTid(tid),
		mSequence(sequence.fetch_add(1, memory_order_relaxed)),
		mRealTime(realtime),
		mMsgLen(len),
		mLogId(log_id),
		@@ -51,6 +51,7 @@ LogBufferElement::LogBufferElement(const LogBufferElement& elem)
		: mUid(elem.mUid),
		mPid(elem.mPid),
		mTid(elem.mTid),
		mSequence(elem.mSequence),
		mRealTime(elem.mRealTime),
		mMsgLen(elem.mMsgLen),
		mLogId(elem.mLogId),
		@@ -244,7 +245,7 @@ size_t LogBufferElement::populateDroppedMessage(char& buffer, LogBuffer parent
		return retval;
		}

		log_time LogBufferElement::flushTo(SocketClient* reader, LogBuffer* parent, bool lastSame) {
		uint64_t LogBufferElement::flushTo(SocketClient* reader, LogBuffer* parent, bool lastSame) {
		struct logger_entry entry = {};

		entry.hdr_size = sizeof(struct logger_entry);
		@@ -263,7 +264,7 @@ log_time LogBufferElement::flushTo(SocketClient* reader, LogBuffer* parent, bool

		if (mDropped) {
		entry.len = populateDroppedMessage(buffer, parent, lastSame);
		if (!entry.len) return mRealTime;
		if (!entry.len) return mSequence;
		iovec[1].iov_base = buffer;
		} else {
		entry.len = mMsgLen;
		@@ -271,9 +272,7 @@ log_time LogBufferElement::flushTo(SocketClient* reader, LogBuffer* parent, bool
		}
		iovec[1].iov_len = entry.len;

		log_time retval = reader->sendDatav(iovec, 1 + (entry.len != 0))
		? FLUSH_ERROR
		: mRealTime;
		uint64_t retval = reader->sendDatav(iovec, 1 + (entry.len != 0)) ? FLUSH_ERROR : mSequence;

		if (buffer) free(buffer);