From 5392aac95d279a7ffc91d8fbcd074307186ca36c Mon Sep 17 00:00:00 2001
From: Mark Salyzyn <salyzyn@google.com>
Date: Fri, 22 May 2015 10:03:31 -0700
Subject: [PATCH 1/2] logd: deal with sloppy leading expire messages

The odds of chatty content also leading the logs is pretty high eg:

 1799 12017 I logd: uid=10007 chatty comm=Binder_B, expire 4 lines
 1799  1829 I logd: uid=10007 chatty comm=Binder_2, expire 4 lines
 1919 20637 I logd: uid=10007 chatty comm=m.sersistent, expire 1 line
 1919 20638 I logd: uid=10007 chatty comm=s.persistent, expire 1 line
 1919  2316 I logd: uid=10007 chatty comm=UlrDispatch, expire 4 lines
19379 20634 I logd: uid=10045 chatty, expire 14 lines
19379 19388 I logd: uid=10045 chatty comm=lizerDaemon, expire 4 lines
  591  4396 I logd: uid=1000 chatty comm=Thread-220, expire 5 lines
  591  1377 I logd: uid=1000 chatty comm=Thread-92, expire 4 lines
 1919  2267 I logd: uid=10007 chatty comm=WifiScanner, expire 4 lines
  591  4397 I logd: uid=1000 chatty comm=DhcpClient, expire 4 lines
  591  4398 I logd: uid=1000 chatty comm=Thread-222, expire 4 lines
  226   580 D CommandListener: Setting iface cfg

Change-Id: I5ab24bc7bf5d2690bae7e789831b07f23ff8bcc6
---
 logd/LogBuffer.cpp | 25 +++++++++++++++----------
 1 file changed, 15 insertions(+), 10 deletions(-)

diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 8c0a0be02..d89a2e7dc 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -417,8 +417,6 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
                 continue;
             }
 
-            leading = false;
-
             if (hasBlacklist && mPrune.naughty(e)) {
                 last.clear(e);
                 it = erase(it);
@@ -448,6 +446,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             }
 
             if (e->getUid() != worst) {
+                leading = false;
                 if (start != log_time::EPOCH) {
                     static const timespec too_old = {
                         EXPIRE_HOUR_THRESHOLD * 60 * 60, 0
@@ -479,15 +478,21 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             kick = true;
 
             unsigned short len = e->getMsgLen();
-            stats.drop(e);
-            e->setDropped(1);
-            if (last.merge(e, 1)) {
-                it = mLogElements.erase(it);
-                stats.erase(e);
-                delete e;
+
+            // do not create any leading drops
+            if (leading) {
+                it = erase(it);
             } else {
-                last.add(e);
-                ++it;
+                stats.drop(e);
+                e->setDropped(1);
+                if (last.merge(e, 1)) {
+                    it = mLogElements.erase(it);
+                    stats.erase(e);
+                    delete e;
+                } else {
+                    last.add(e);
+                    ++it;
+                }
             }
             if (worst_sizes < second_worst_sizes) {
                 break;

From 5921276a16528bf79292e828080bf0ec984cbb23 Mon Sep 17 00:00:00 2001
From: Mark Salyzyn <salyzyn@google.com>
Date: Mon, 1 Jun 2015 09:41:19 -0700
Subject: [PATCH 2/2] logd: KISS & fix preserve a day

Code in 833a9b1e38ce65f2cdf3ebd095aaa99a92eb9467 was borken,
simpler approach is to simply check last entry (to save a
syscall) minus EXPIRE_HOUR_THRESHOLD. This does make longer logs
less likely to call upon the spam detection than the algorithm
being replaced, but sadly we ended up with a log entry in the
future at the beginning of the logs confounding the previous
algorithm.

Bug: 21555259
Change-Id: I04fad67e95c8496521dbabb73b5f32c19d6a16c2
---
 logd/LogBuffer.cpp | 25 +++++++++----------------
 1 file changed, 9 insertions(+), 16 deletions(-)

diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index d89a2e7dc..913e1f11f 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -388,7 +388,6 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
         bool kick = false;
         bool leading = true;
         LogBufferElementLast last;
-        log_time start(log_time::EPOCH);
         for(it = mLogElements.begin(); it != mLogElements.end();) {
             LogBufferElement *e = *it;
 
@@ -446,30 +445,24 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             }
 
             if (e->getUid() != worst) {
-                leading = false;
-                if (start != log_time::EPOCH) {
+                if (leading) {
                     static const timespec too_old = {
                         EXPIRE_HOUR_THRESHOLD * 60 * 60, 0
                     };
-                    start = e->getRealTime() + too_old;
+                    LogBufferElementCollection::iterator last;
+                    last = mLogElements.end();
+                    --last;
+                    if ((e->getRealTime() < ((*last)->getRealTime() - too_old))
+                            || (e->getRealTime() > (*last)->getRealTime())) {
+                        break;
+                    }
                 }
+                leading = false;
                 last.clear(e);
                 ++it;
                 continue;
             }
 
-            if ((start != log_time::EPOCH) && (e->getRealTime() > start)) {
-                // KISS. Really a heuristic rather than algorithmically strong,
-                // a crude mechanism, the following loops will move the oldest
-                // watermark possibly wiping out the extra EXPIRE_HOUR_THRESHOLD
-                // we just thought we were preserving. We count on the typical
-                // pruneRows of 10% of total not being a sledgehammer.
-                // A stronger algorithm would have us loop back to the top if
-                // we have worst-UID enabled and we start expiring messages
-                // below less than EXPIRE_HOUR_THRESHOLD old.
-                break;
-            }
-
             pruneRows--;
             if (pruneRows == 0) {
                 break;