Commit: 56f7e9719f4b2615426d01baeff0584a7eb88614 - system-coremmmm (git)

system/corennnnn

Commit MetaInfo

• Revision: 56f7e9719f4b2615426d01baeff0584a7eb88614 (tree)
• Zeit: 2015-12-22 11:59:30
• Autor: TraianX Schiau <traianx.schiau@inte...>
• Commiter: Chih-Wei Huang

Log Message

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 <[e-mail]>

Ändern Zusammenfassung

• modified: logd/LogBuffer.cpp
• modified: logd/LogTimes.cpp
• modified: logd/LogTimes.h

Diff

--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -241,7 +241,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
     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;
         }
@@ -353,7 +353,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
                         // kick a misbehaving log reader client off the island
                         oldest->release_Locked();
                     } else {
-                        oldest->triggerSkip_Locked(pruneRows);
+                        oldest->triggerSkip_Locked(id, pruneRows);
                     }
                 }
                 break;
@@ -384,7 +384,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
                         // kick a misbehaving log reader client off the island
                         oldest->release_Locked();
                     } else {
-                        oldest->triggerSkip_Locked(pruneRows);
+                        oldest->triggerSkip_Locked(id, pruneRows);
                     }
                     break;
                 }

--- a/logd/LogTimes.cpp
+++ b/logd/LogTimes.cpp
@@ -36,7 +36,6 @@ LogTimeEntry::LogTimeEntry(LogReader &reader, SocketClient *client,
         , mReader(reader)
         , mLogMask(logMask)
         , mPid(pid)
-        , skipAhead(0)
         , mCount(0)
         , mTail(tail)
         , mIndex(0)
@@ -46,6 +45,7 @@ LogTimeEntry::LogTimeEntry(LogReader &reader, SocketClient *client,
         , mEnd(CLOCK_MONOTONIC)
 {
         pthread_cond_init(&threadTriggeredCondition, NULL);
+        cleanSkip_Locked();
 }
 
 void LogTimeEntry::startReader_Locked(void) {
@@ -148,6 +148,8 @@ void *LogTimeEntry::threadStart(void *obj) {
             break;
         }
 
+        me->cleanSkip_Locked();
+
         pthread_cond_wait(&me->threadTriggeredCondition, &timesLock);
     }
 
@@ -169,7 +171,7 @@ bool LogTimeEntry::FilterFirstPass(const LogBufferElement *element, void *obj) {
     }
 
     if ((!me->mPid || (me->mPid == element->getPid()))
-            && (me->mLogMask & (1 << element->getLogId()))) {
+            && (me->isWatching(element->getLogId()))) {
         ++me->mCount;
     }
 
@@ -184,19 +186,19 @@ bool LogTimeEntry::FilterSecondPass(const LogBufferElement *element, void *obj)
 
     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 @@ bool LogTimeEntry::FilterSecondPass(const LogBufferElement *element, void *obj)
     }
 
 ok:
-    if (!me->skipAhead) {
+    if (!me->skipAhead[element->getLogId()]) {
         LogTimeEntry::unlock();
         return true;
     }
@@ -233,3 +235,9 @@ skip:
     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;
+    }
+}

--- 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 @@ class LogTimeEntry {
     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 @@ public:
         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 @@ public:
         // 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);