logd: clear return and deal with busy if readers locked

- Propagate to caller the clearing errors, busy blocked by reader.
- For clear, perform retries within logd with a one second lul each,
  telling readers to skip, but on final retry to kill all readers if
  problem still persists due to block reader (or high volume logspammer).

Bug: 23711431
Change-Id: Ie4c46bc9480a7f49b96a81fae25a95c603270c33

3 files changed, 53 insertions, 10 deletions

diff --git a/logd/CommandListener.cpp b/logd/CommandListener.cpp
index 031c74018..eafa28fb4 100644
--- a/logd/CommandListener.cpp
+++ b/logd/CommandListener.cpp
@@ -96,8 +96,7 @@ int CommandListener::ClearCmd::runCommand(SocketClient *cli,
         return 0;
     }
 
-    mBuf.clear((log_id_t) id, uid);
-    cli->sendMsg("success");
+    cli->sendMsg(mBuf.clear((log_id_t) id, uid) ? "busy" : "success");
     return 0;
 }
 
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index c2f846ef2..35ee6f365 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -374,8 +374,9 @@ public:
 //
 // mLogElementsLock must be held when this function is called.
 //
-void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
+bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
     LogTimeEntry *oldest = NULL;
+    bool busy = false;
 
     LogTimeEntry::lock();
 
@@ -397,6 +398,8 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             LogBufferElement *e = *it;
 
             if (oldest && (oldest->mStart <= e->getSequence())) {
+                oldest->triggerSkip_Locked(id, pruneRows);
+                busy = true;
                 break;
             }
 
@@ -416,7 +419,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             }
         }
         LogTimeEntry::unlock();
-        return;
+        return busy;
     }
 
     // prune by worst offender by uid
@@ -478,6 +481,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             LogBufferElement *e = *it;
 
             if (oldest && (oldest->mStart <= e->getSequence())) {
+                busy = true;
                 break;
             }
 
@@ -596,6 +600,8 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
         }
 
         if (oldest && (oldest->mStart <= e->getSequence())) {
+            busy = true;
+
             if (whitelist) {
                 break;
             }
@@ -631,6 +637,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             }
 
             if (oldest && (oldest->mStart <= e->getSequence())) {
+                busy = true;
                 if (stats.sizes(id) > (2 * log_buffer_size(id))) {
                     // kick a misbehaving log reader client off the island
                     oldest->release_Locked();
@@ -646,13 +653,50 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
     }
 
     LogTimeEntry::unlock();
+
+    return (pruneRows > 0) && busy;
 }
 
 // clear all rows of type "id" from the buffer.
-void LogBuffer::clear(log_id_t id, uid_t uid) {
-    pthread_mutex_lock(&mLogElementsLock);
-    prune(id, ULONG_MAX, uid);
-    pthread_mutex_unlock(&mLogElementsLock);
+bool LogBuffer::clear(log_id_t id, uid_t uid) {
+    bool busy = true;
+    // If it takes more than 4 tries (seconds) to clear, then kill reader(s)
+    for (int retry = 4;;) {
+        if (retry == 1) { // last pass
+            // Check if it is still busy after the sleep, we say prune
+            // 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);
+            busy = prune(id, 1, uid);
+            pthread_mutex_unlock(&mLogElementsLock);
+            // 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();
+                LastLogTimes::iterator times = mTimes.begin();
+                while (times != mTimes.end()) {
+                    LogTimeEntry *entry = (*times);
+                    // Killer punch
+                    if (entry->owned_Locked() && entry->isWatching(id)) {
+                        entry->release_Locked();
+                    }
+                    times++;
+                }
+                LogTimeEntry::unlock();
+            }
+        }
+        pthread_mutex_lock(&mLogElementsLock);
+        busy = prune(id, ULONG_MAX, uid);
+        pthread_mutex_unlock(&mLogElementsLock);
+        if (!busy || !--retry) {
+            break;
+        }
+        sleep (1); // Let reader(s) catch up after notification
+    }
+    return busy;
 }
 
 // get the used space associated with "id".
diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h
index de7669310..d8e0b90f2 100644
--- a/logd/LogBuffer.h
+++ b/logd/LogBuffer.h
@@ -63,7 +63,7 @@ public:
                      int (*filter)(const LogBufferElement *element, void *arg) = NULL,
                      void *arg = NULL);
 
-    void clear(log_id_t id, uid_t uid = AID_ROOT);
+    bool clear(log_id_t id, uid_t uid = AID_ROOT);
     unsigned long getSize(log_id_t id);
     int setSize(log_id_t id, unsigned long size);
     unsigned long getSizeUsed(log_id_t id);
@@ -86,7 +86,7 @@ public:
 
 private:
     void maybePrune(log_id_t id);
-    void prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT);
+    bool prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT);
     LogBufferElementCollection::iterator erase(
         LogBufferElementCollection::iterator it, bool engageStats = true);
 };