Merge commit 'd950b7b5f303a534313070cfbee66f6ab0d05c16' of persistent-https://googleplex-android.git.corp.google.com/platform/system/core into OCSYNC
Change-Id: I71eaacaabf99c31c0904c40c2eafe57c366b0432
diff --git a/logd/FlushCommand.cpp b/logd/FlushCommand.cpp
index c67d2bf..a9edc3e 100644
--- a/logd/FlushCommand.cpp
+++ b/logd/FlushCommand.cpp
@@ -44,14 +44,14 @@
// LogTimeEntrys, and spawn a transitory per-client thread to
// work at filing data to the socket.
//
-// global LogTimeEntry::lock() is used to protect access,
+// global LogTimeEntry::wrlock() is used to protect access,
// reference counts are used to ensure that individual
// LogTimeEntry lifetime is managed when not protected.
void FlushCommand::runSocketCommand(SocketClient* client) {
LogTimeEntry* entry = NULL;
LastLogTimes& times = mReader.logbuf().mTimes;
- LogTimeEntry::lock();
+ LogTimeEntry::wrlock();
LastLogTimes::iterator it = times.begin();
while (it != times.end()) {
entry = (*it);
diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp
index 2d9024a..ee38d1c 100644
--- a/logd/LogAudit.cpp
+++ b/logd/LogAudit.cpp
@@ -277,7 +277,7 @@
++cp;
}
tid = pid;
- logbuf->lock();
+ logbuf->wrlock();
uid = logbuf->pidToUid(pid);
logbuf->unlock();
memmove(pidptr, cp, strlen(cp) + 1);
@@ -322,7 +322,7 @@
pid = tid;
comm = "auditd";
} else {
- logbuf->lock();
+ logbuf->wrlock();
comm = commfree = logbuf->pidToName(pid);
logbuf->unlock();
if (!comm) {
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 4aa2c9f..e4636c3 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -72,7 +72,7 @@
// as the act of mounting /data would trigger persist.logd.timestamp to
// be corrected. 1/30 corner case YMMV.
//
- pthread_mutex_lock(&mLogElementsLock);
+ rdlock();
LogBufferElementCollection::iterator it = mLogElements.begin();
while ((it != mLogElements.end())) {
LogBufferElement* e = *it;
@@ -87,7 +87,7 @@
}
++it;
}
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
}
// We may have been triggered by a SIGHUP. Release any sleeping reader
@@ -95,7 +95,7 @@
//
// NB: this is _not_ performed in the context of a SIGHUP, it is
// performed during startup, and in context of reinit administrative thread
- LogTimeEntry::lock();
+ LogTimeEntry::wrlock();
LastLogTimes::iterator times = mTimes.begin();
while (times != mTimes.end()) {
@@ -111,7 +111,7 @@
LogBuffer::LogBuffer(LastLogTimes* times)
: monotonic(android_log_clockid() == CLOCK_MONOTONIC), mTimes(*times) {
- pthread_mutex_init(&mLogElementsLock, nullptr);
+ pthread_rwlock_init(&mLogElementsLock, nullptr);
log_id_for_each(i) {
lastLoggedElements[i] = nullptr;
@@ -209,16 +209,15 @@
}
if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) {
// Log traffic received to total
- pthread_mutex_lock(&mLogElementsLock);
- stats.add(elem);
- stats.subtract(elem);
- pthread_mutex_unlock(&mLogElementsLock);
+ wrlock();
+ stats.addTotal(elem);
+ unlock();
delete elem;
return -EACCES;
}
}
- pthread_mutex_lock(&mLogElementsLock);
+ wrlock();
LogBufferElement* currentLast = lastLoggedElements[log_id];
if (currentLast) {
LogBufferElement* dropped = droppedElements[log_id];
@@ -319,15 +318,14 @@
// check for overflow
if (total >= UINT32_MAX) {
log(currentLast);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return len;
}
- stats.add(currentLast);
- stats.subtract(currentLast);
+ stats.addTotal(currentLast);
delete currentLast;
swab = total;
event->payload.data = htole32(swab);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return len;
}
if (count == USHRT_MAX) {
@@ -339,13 +337,12 @@
}
}
if (count) {
- stats.add(currentLast);
- stats.subtract(currentLast);
+ stats.addTotal(currentLast);
currentLast->setDropped(count);
}
droppedElements[log_id] = currentLast;
lastLoggedElements[log_id] = elem;
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return len;
}
if (dropped) { // State 1 or 2
@@ -363,12 +360,12 @@
lastLoggedElements[log_id] = new LogBufferElement(*elem);
log(elem);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return len;
}
-// assumes mLogElementsLock held, owns elem, will look after garbage collection
+// 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
@@ -389,7 +386,7 @@
bool end_set = false;
bool end_always = false;
- LogTimeEntry::lock();
+ LogTimeEntry::rdlock();
LastLogTimes::iterator times = mTimes.begin();
while (times != mTimes.end()) {
@@ -431,7 +428,7 @@
// Prune at most 10% of the log entries or maxPrune, whichever is less.
//
-// mLogElementsLock must be held when this function is called.
+// LogBuffer::wrlock() 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);
@@ -610,6 +607,33 @@
}
};
+// 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) {
+ if (stats.sizes(id) > (2 * log_buffer_size(id))) { // +100%
+ // A misbehaving or slow reader has its connection
+ // dropped if we hit too much memory pressure.
+ me->release_Locked();
+ } else if (me->mTimeout.tv_sec || me->mTimeout.tv_nsec) {
+ // Allow a blocked WRAP timeout reader to
+ // trigger and start reporting the log data.
+ me->triggerReader_Locked();
+ } else {
+ // tell slow reader to skip entries to catch up
+ me->triggerSkip_Locked(id, pruneRows);
+ }
+}
+
// prune "pruneRows" of type "id" from the buffer.
//
// This garbage collection task is used to expire log entries. It is called to
@@ -655,14 +679,14 @@
// The third thread is optional, and only gets hit if there was a whitelist
// and more needs to be pruned against the backstop of the region lock.
//
-// mLogElementsLock must be held when this function is called.
+// LogBuffer::wrlock() must be held when this function is called.
//
bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
LogTimeEntry* oldest = nullptr;
bool busy = false;
bool clearAll = pruneRows == ULONG_MAX;
- LogTimeEntry::lock();
+ LogTimeEntry::rdlock();
// Region locked?
LastLogTimes::iterator times = mTimes.begin();
@@ -700,12 +724,8 @@
}
if (oldest && (watermark <= element->getRealTime())) {
- busy = true;
- if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
- oldest->triggerReader_Locked();
- } else {
- oldest->triggerSkip_Locked(id, pruneRows);
- }
+ busy = isBusy(watermark);
+ if (busy) kickMe(oldest, id, pruneRows);
break;
}
@@ -792,10 +812,8 @@
LogBufferElement* element = *it;
if (oldest && (watermark <= element->getRealTime())) {
- busy = true;
- if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
- oldest->triggerReader_Locked();
- }
+ busy = isBusy(watermark);
+ // Do not let chatty eliding trigger any reader mitigation
break;
}
@@ -946,19 +964,8 @@
}
if (oldest && (watermark <= element->getRealTime())) {
- busy = true;
- if (whitelist) {
- break;
- }
-
- if (stats.sizes(id) > (2 * log_buffer_size(id))) {
- // kick a misbehaving log reader client off the island
- oldest->release_Locked();
- } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
- oldest->triggerReader_Locked();
- } else {
- oldest->triggerSkip_Locked(id, pruneRows);
- }
+ busy = isBusy(watermark);
+ if (!whitelist && busy) kickMe(oldest, id, pruneRows);
break;
}
@@ -990,15 +997,8 @@
}
if (oldest && (watermark <= element->getRealTime())) {
- busy = true;
- if (stats.sizes(id) > (2 * log_buffer_size(id))) {
- // kick a misbehaving log reader client off the island
- oldest->release_Locked();
- } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
- oldest->triggerReader_Locked();
- } else {
- oldest->triggerSkip_Locked(id, pruneRows);
- }
+ busy = isBusy(watermark);
+ if (busy) kickMe(oldest, id, pruneRows);
break;
}
@@ -1022,15 +1022,15 @@
// one entry, not another clear run, so we are looking for
// the quick side effect of the return value to tell us if
// we have a _blocked_ reader.
- pthread_mutex_lock(&mLogElementsLock);
+ wrlock();
busy = prune(id, 1, uid);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
// It is still busy, blocked reader(s), lets kill them all!
// otherwise, lets be a good citizen and preserve the slow
// readers and let the clear run (below) deal with determining
// if we are still blocked and return an error code to caller.
if (busy) {
- LogTimeEntry::lock();
+ LogTimeEntry::wrlock();
LastLogTimes::iterator times = mTimes.begin();
while (times != mTimes.end()) {
LogTimeEntry* entry = (*times);
@@ -1043,9 +1043,9 @@
LogTimeEntry::unlock();
}
}
- pthread_mutex_lock(&mLogElementsLock);
+ wrlock();
busy = prune(id, ULONG_MAX, uid);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
if (!busy || !--retry) {
break;
}
@@ -1056,9 +1056,9 @@
// get the used space associated with "id".
unsigned long LogBuffer::getSizeUsed(log_id_t id) {
- pthread_mutex_lock(&mLogElementsLock);
+ rdlock();
size_t retval = stats.sizes(id);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return retval;
}
@@ -1068,17 +1068,17 @@
if (!__android_logger_valid_buffer_size(size)) {
return -1;
}
- pthread_mutex_lock(&mLogElementsLock);
+ wrlock();
log_buffer_size(id) = size;
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return 0;
}
// get the total space allocated to "id"
unsigned long LogBuffer::getSize(log_id_t id) {
- pthread_mutex_lock(&mLogElementsLock);
+ rdlock();
size_t retval = log_buffer_size(id);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return retval;
}
@@ -1090,7 +1090,7 @@
LogBufferElementCollection::iterator it;
uid_t uid = reader->getUid();
- pthread_mutex_lock(&mLogElementsLock);
+ rdlock();
if (start == log_time::EPOCH) {
// client wants to start from the beginning
@@ -1148,7 +1148,7 @@
continue;
}
- // NB: calling out to another object with mLogElementsLock held (safe)
+ // NB: calling out to another object with wrlock() held (safe)
if (filter) {
int ret = (*filter)(element, arg);
if (ret == false) {
@@ -1171,7 +1171,7 @@
(element->getDropped() && !sameTid) ? 0 : element->getTid();
}
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
// range locking in LastLogTimes looks after us
max = element->flushTo(reader, this, privileged, sameTid);
@@ -1181,20 +1181,20 @@
}
skip = maxSkip;
- pthread_mutex_lock(&mLogElementsLock);
+ rdlock();
}
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return max;
}
std::string LogBuffer::formatStatistics(uid_t uid, pid_t pid,
unsigned int logMask) {
- pthread_mutex_lock(&mLogElementsLock);
+ wrlock();
std::string ret = stats.format(uid, pid, logMask);
- pthread_mutex_unlock(&mLogElementsLock);
+ unlock();
return ret;
}
diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h
index 1272c20..c3464eb 100644
--- a/logd/LogBuffer.h
+++ b/logd/LogBuffer.h
@@ -76,7 +76,7 @@
class LogBuffer {
LogBufferElementCollection mLogElements;
- pthread_mutex_t mLogElementsLock;
+ pthread_rwlock_t mLogElementsLock;
LogStatistics stats;
@@ -154,7 +154,7 @@
return tags.tagToName(tag);
}
- // helper must be protected directly or implicitly by lock()/unlock()
+ // helper must be protected directly or implicitly by wrlock()/unlock()
const char* pidToName(pid_t pid) {
return stats.pidToName(pid);
}
@@ -164,11 +164,14 @@
const char* uidToName(uid_t uid) {
return stats.uidToName(uid);
}
- void lock() {
- pthread_mutex_lock(&mLogElementsLock);
+ void wrlock() {
+ pthread_rwlock_wrlock(&mLogElementsLock);
+ }
+ void rdlock() {
+ pthread_rwlock_rdlock(&mLogElementsLock);
}
void unlock() {
- pthread_mutex_unlock(&mLogElementsLock);
+ pthread_rwlock_unlock(&mLogElementsLock);
}
private:
@@ -177,6 +180,9 @@
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);
LogBufferElementCollection::iterator erase(
LogBufferElementCollection::iterator it, bool coalesce = false);
diff --git a/logd/LogBufferElement.cpp b/logd/LogBufferElement.cpp
index 04a620c..381c974 100644
--- a/logd/LogBufferElement.cpp
+++ b/logd/LogBufferElement.cpp
@@ -121,7 +121,7 @@
}
static const char format_uid[] = "uid=%u%s%s %s %u line%s";
- parent->lock();
+ parent->wrlock();
const char* name = parent->uidToName(mUid);
parent->unlock();
const char* commName = android::tidToName(mTid);
@@ -129,7 +129,7 @@
commName = android::tidToName(mPid);
}
if (!commName) {
- parent->lock();
+ parent->wrlock();
commName = parent->pidToName(mPid);
parent->unlock();
}
diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp
index d23254d..a7e7208 100644
--- a/logd/LogKlog.cpp
+++ b/logd/LogKlog.cpp
@@ -579,7 +579,7 @@
const pid_t tid = pid;
uid_t uid = AID_ROOT;
if (pid) {
- logbuf->lock();
+ logbuf->wrlock();
uid = logbuf->pidToUid(pid);
logbuf->unlock();
}
diff --git a/logd/LogReader.cpp b/logd/LogReader.cpp
index af19279..a6844f8 100644
--- a/logd/LogReader.cpp
+++ b/logd/LogReader.cpp
@@ -110,7 +110,7 @@
if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) {
// Allow writer to get some cycles, and wait for pending notifications
sched_yield();
- LogTimeEntry::lock();
+ LogTimeEntry::wrlock();
LogTimeEntry::unlock();
sched_yield();
nonBlock = true;
@@ -205,7 +205,7 @@
void LogReader::doSocketDelete(SocketClient* cli) {
LastLogTimes& times = mLogbuf.mTimes;
- LogTimeEntry::lock();
+ LogTimeEntry::wrlock();
LastLogTimes::iterator it = times.begin();
while (it != times.end()) {
LogTimeEntry* entry = (*it);
diff --git a/logd/LogStatistics.cpp b/logd/LogStatistics.cpp
index cc30f77..adcc035 100644
--- a/logd/LogStatistics.cpp
+++ b/logd/LogStatistics.cpp
@@ -15,6 +15,7 @@
*/
#include <fcntl.h>
+#include <inttypes.h>
#include <pwd.h>
#include <stdio.h>
#include <string.h>
@@ -70,20 +71,30 @@
}
}
+void LogStatistics::addTotal(LogBufferElement* element) {
+ if (element->getDropped()) return;
+
+ log_id_t log_id = element->getLogId();
+ unsigned short size = element->getMsgLen();
+ mSizesTotal[log_id] += size;
+ SizesTotal += size;
+ ++mElementsTotal[log_id];
+}
+
void LogStatistics::add(LogBufferElement* element) {
log_id_t log_id = element->getLogId();
unsigned short size = element->getMsgLen();
mSizes[log_id] += size;
++mElements[log_id];
+ // When caller adding a chatty entry, they will have already
+ // called add() and subtract() for each entry as they are
+ // evaluated and trimmed, thus recording size and number of
+ // elements, but we must recognize the manufactured dropped
+ // entry as not contributing to the lifetime totals.
if (element->getDropped()) {
++mDroppedElements[log_id];
} else {
- // When caller adding a chatty entry, they will have already
- // called add() and subtract() for each entry as they are
- // evaluated and trimmed, thus recording size and number of
- // elements, but we must recognize the manufactured dropped
- // entry as not contributing to the lifetime totals.
mSizesTotal[log_id] += size;
SizesTotal += size;
++mElementsTotal[log_id];
@@ -181,6 +192,7 @@
}
// caller must own and free character string
+// Requires parent LogBuffer::wrlock() to be held
const char* LogStatistics::uidToName(uid_t uid) const {
// Local hard coded favourites
if (uid == AID_LOGD) {
diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h
index 066b7de..e171e4a 100644
--- a/logd/LogStatistics.h
+++ b/logd/LogStatistics.h
@@ -576,6 +576,7 @@
enable = true;
}
+ void addTotal(LogBufferElement* entry);
void add(LogBufferElement* entry);
void subtract(LogBufferElement* entry);
// entry->setDropped(1) must follow this call
diff --git a/logd/LogTimes.cpp b/logd/LogTimes.cpp
index ccc550a..25c2ad2 100644
--- a/logd/LogTimes.cpp
+++ b/logd/LogTimes.cpp
@@ -78,7 +78,7 @@
void LogTimeEntry::threadStop(void* obj) {
LogTimeEntry* me = reinterpret_cast<LogTimeEntry*>(obj);
- lock();
+ wrlock();
if (me->mNonBlock) {
me->error_Locked();
@@ -134,7 +134,7 @@
me->leadingDropped = true;
- lock();
+ wrlock();
log_time start = me->mStart;
@@ -160,7 +160,7 @@
start = logbuf.flushTo(client, start, me->mLastTid, privileged,
security, FilterSecondPass, me);
- lock();
+ wrlock();
if (start == LogBufferElement::FLUSH_ERROR) {
me->error_Locked();
@@ -191,7 +191,7 @@
int LogTimeEntry::FilterFirstPass(const LogBufferElement* element, void* obj) {
LogTimeEntry* me = reinterpret_cast<LogTimeEntry*>(obj);
- LogTimeEntry::lock();
+ LogTimeEntry::wrlock();
if (me->leadingDropped) {
if (element->getDropped()) {
@@ -219,7 +219,7 @@
int LogTimeEntry::FilterSecondPass(const LogBufferElement* element, void* obj) {
LogTimeEntry* me = reinterpret_cast<LogTimeEntry*>(obj);
- LogTimeEntry::lock();
+ LogTimeEntry::wrlock();
me->mStart = element->getRealTime();
diff --git a/logd/LogTimes.h b/logd/LogTimes.h
index ec8252e..9ca2aea 100644
--- a/logd/LogTimes.h
+++ b/logd/LogTimes.h
@@ -61,7 +61,10 @@
const log_time mEnd; // only relevant if mNonBlock
// Protect List manipulations
- static void lock(void) {
+ static void wrlock(void) {
+ pthread_mutex_lock(×Lock);
+ }
+ static void rdlock(void) {
pthread_mutex_lock(×Lock);
}
static void unlock(void) {
@@ -104,7 +107,7 @@
mError = true;
}
void error(void) {
- lock();
+ wrlock();
error_Locked();
unlock();
}
