logd: Fix pruning
In a scenario in which an on-line (blocking) client is running and
a clean is attempted (logcat -c), the following can be observed:
1) the on-line logger seems to freeze
2) any other clear attempt will have no effect
What is actually happening:
In this case prune function will "instruct" the oldest timeEntry
to skip a huge number (very close to ULONG_MAX) of messages, this
being the cause of 1.
Since the consumer thread will skip all the log entries, mStart
updating will also be skipped. So a new cleaning attempt will have
the same oldest entry, nothing will be done.
Fix description:
a. keep a separated skipAhead count for individual log buffers (log_id_t)
LogTimeEntry::LogTimeEntry
LogTimeEntry::FilterSecondPass
LogTimeEntry::skipAhead
LogTimeEntry::riggerSkip_Locked
b. update LogTimeEntry::mStart even if the current message is skipped
LogTimeEntry::FilterSecondPass
c. while pruning, only take into account the LogTimeEntrys that are monitoring
the log_id in question, and provide a public method of checking this.
LogTimeEntry::isWatching
LogTimeEntry::FilterFirstPass
LogTimeEntry::FilterSecondPass
d. Reset the skip cont befor the client thtread starts to sleep, at this point
we should be up to date.
LogTimeEntry::cleanSkip_Locked
LogTimeEntry::threadStart
Change-Id: I1b369dc5b02476e633e52578266a644e37e188a5
Signed-off-by: TraianX Schiau <traianx.schiau@intel.com>
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 1c74ba5..6307bed 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -242,7 +242,7 @@
LastLogTimes::iterator t = mTimes.begin();
while(t != mTimes.end()) {
LogTimeEntry *entry = (*t);
- if (entry->owned_Locked()
+ if (entry->owned_Locked() && entry->isWatching(id)
&& (!oldest || (oldest->mStart > entry->mStart))) {
oldest = entry;
}
@@ -354,7 +354,7 @@
// kick a misbehaving log reader client off the island
oldest->release_Locked();
} else {
- oldest->triggerSkip_Locked(pruneRows);
+ oldest->triggerSkip_Locked(id, pruneRows);
}
}
break;
@@ -385,7 +385,7 @@
// kick a misbehaving log reader client off the island
oldest->release_Locked();
} else {
- oldest->triggerSkip_Locked(pruneRows);
+ oldest->triggerSkip_Locked(id, pruneRows);
}
break;
}
diff --git a/logd/LogTimes.cpp b/logd/LogTimes.cpp
index ea4e8c8..5f9db8d 100644
--- a/logd/LogTimes.cpp
+++ b/logd/LogTimes.cpp
@@ -36,7 +36,6 @@
, mReader(reader)
, mLogMask(logMask)
, mPid(pid)
- , skipAhead(0)
, mCount(0)
, mTail(tail)
, mIndex(0)
@@ -46,6 +45,7 @@
, mEnd(CLOCK_MONOTONIC)
{
pthread_cond_init(&threadTriggeredCondition, NULL);
+ cleanSkip_Locked();
}
void LogTimeEntry::startReader_Locked(void) {
@@ -148,6 +148,8 @@
break;
}
+ me->cleanSkip_Locked();
+
pthread_cond_wait(&me->threadTriggeredCondition, ×Lock);
}
@@ -169,7 +171,7 @@
}
if ((!me->mPid || (me->mPid == element->getPid()))
- && (me->mLogMask & (1 << element->getLogId()))) {
+ && (me->isWatching(element->getLogId()))) {
++me->mCount;
}
@@ -184,19 +186,19 @@
LogTimeEntry::lock();
- if (me->skipAhead) {
- me->skipAhead--;
+ me->mStart = element->getMonotonicTime();
+
+ if (me->skipAhead[element->getLogId()]) {
+ me->skipAhead[element->getLogId()]--;
goto skip;
}
- me->mStart = element->getMonotonicTime();
-
// Truncate to close race between first and second pass
if (me->mNonBlock && me->mTail && (me->mIndex >= me->mCount)) {
goto skip;
}
- if ((me->mLogMask & (1 << element->getLogId())) == 0) {
+ if (!me->isWatching(element->getLogId())) {
goto skip;
}
@@ -223,7 +225,7 @@
}
ok:
- if (!me->skipAhead) {
+ if (!me->skipAhead[element->getLogId()]) {
LogTimeEntry::unlock();
return true;
}
@@ -233,3 +235,9 @@
LogTimeEntry::unlock();
return false;
}
+
+void LogTimeEntry::cleanSkip_Locked(void) {
+ for (log_id_t i = LOG_ID_MIN; i < LOG_ID_MAX; i = (log_id_t) (i + 1)) {
+ skipAhead[i] = 0;
+ }
+}
diff --git a/logd/LogTimes.h b/logd/LogTimes.h
index 0bfa7a2..81aedfb 100644
--- a/logd/LogTimes.h
+++ b/logd/LogTimes.h
@@ -22,6 +22,7 @@
#include <sys/types.h>
#include <sysutils/SocketClient.h>
#include <utils/List.h>
+#include <log/log.h>
class LogReader;
@@ -38,7 +39,7 @@
static void threadStop(void *me);
const unsigned int mLogMask;
const pid_t mPid;
- unsigned int skipAhead;
+ unsigned int skipAhead[LOG_ID_MAX];
unsigned long mCount;
unsigned long mTail;
unsigned long mIndex;
@@ -67,7 +68,8 @@
pthread_cond_signal(&threadTriggeredCondition);
}
- void triggerSkip_Locked(unsigned int skip) { skipAhead = skip; }
+ void triggerSkip_Locked(log_id_t id, unsigned int skip) { skipAhead[id] = skip; }
+ void cleanSkip_Locked(void);
// Called after LogTimeEntry removed from list, lock implicitly held
void release_Locked(void) {
@@ -99,7 +101,7 @@
// No one else is holding a reference to this
delete this;
}
-
+ bool isWatching(log_id_t id) { return (mLogMask & (1<<id)) != 0; }
// flushTo filter callbacks
static bool FilterFirstPass(const LogBufferElement *element, void *me);
static bool FilterSecondPass(const LogBufferElement *element, void *me);