From 1d84f0b2afd36c4a6a367761c3d518789a424419 Mon Sep 17 00:00:00 2001
From: Mark Salyzyn <salyzyn@google.com>
Date: Fri, 3 Mar 2017 10:21:23 -0800
Subject: [PATCH] logd: ensure LogBufferElement mSequence is monotonic

- Improves accuracy of -t/-T '<timestamp>' behavior when out of order
  arrival of entries messes with mSequence as the list will now have
  monotonic sequence numbers enforced.
- Out of order time entries still remain because of reader requiring
  the ability to receive newly arrived old entries.
- -t/-T '<timestamp>' can still quit backward search prematurely
  because an old entry lands later in the list.
- Adjust insert in place algorithm from two loops of scan placement
  and then limit against watermark, into one that does all of that
  plus iteratively swap update the sequence numbers to set
  monotonicity.  Side effect will be that the read lock (which is
  actually the LogTimes lock) will be held longer while we search
  for a placement above the youngest LogTimes watermark.  We need
  to hold the read (LogTimes) lock because we may be altering the
  sequence numbers affecting -t/-T '<timestamp>' search.

Test: gTest logd-unit-tests liblog-unit-tests logcat-unit-tests
Bug: 35373582
Change-Id: I79a385fc149bac2179128b53d4c8f71e429181ae
---
 logd/LogBuffer.cpp      | 29 ++++++++++++++++++-----------
 logd/LogBufferElement.h |  2 +-
 2 files changed, 19 insertions(+), 12 deletions(-)

diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 2b6c27688..fbd04ef8c 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -27,6 +27,7 @@
 #include <unistd.h>
 
 #include <unordered_map>
+#include <utility>
 
 #include <cutils/properties.h>
 #include <private/android_logger.h>
@@ -374,15 +375,9 @@ void LogBuffer::log(LogBufferElement* elem) {
     //  NB: if end is region locked, place element at end of list
     LogBufferElementCollection::iterator it = mLogElements.end();
     LogBufferElementCollection::iterator last = it;
-    while (last != mLogElements.begin()) {
-        --it;
-        if ((*it)->getRealTime() <= elem->getRealTime()) {
-            break;
-        }
-        last = it;
-    }
-
-    if (last == mLogElements.end()) {
+    if (__predict_true(it != mLogElements.begin())) --it;
+    if (__predict_false(it == mLogElements.begin()) ||
+        __predict_true((*it)->getRealTime() <= elem->getRealTime())) {
         mLogElements.push_back(elem);
     } else {
         uint64_t end = 1;
@@ -399,6 +394,7 @@ void LogBuffer::log(LogBufferElement* elem) {
                     end_always = true;
                     break;
                 }
+                // it passing mEnd is blocked by the following checks.
                 if (!end_set || (end <= entry->mEnd)) {
                     end = entry->mEnd;
                     end_set = true;
@@ -407,12 +403,23 @@ void LogBuffer::log(LogBufferElement* elem) {
             times++;
         }
 
-        if (end_always || (end_set && (end >= (*last)->getSequence()))) {
+        if (end_always || (end_set && (end > (*it)->getSequence()))) {
             mLogElements.push_back(elem);
         } else {
+            // should be short as timestamps are localized near end()
+            do {
+                last = it;
+                if (__predict_false(it == mLogElements.begin())) {
+                    break;
+                }
+
+                std::swap((*it)->mSequence, elem->mSequence);
+
+                --it;
+            } while (((*it)->getRealTime() > elem->getRealTime()) &&
+                     (!end_set || (end <= (*it)->getSequence())));
             mLogElements.insert(last, elem);
         }
-
         LogTimeEntry::unlock();
     }
 
diff --git a/logd/LogBufferElement.h b/logd/LogBufferElement.h
index 43990e835..90756dd4b 100644
--- a/logd/LogBufferElement.h
+++ b/logd/LogBufferElement.h
@@ -40,7 +40,7 @@ class LogBufferElement {
     const uint32_t mUid;
     const uint32_t mPid;
     const uint32_t mTid;
-    const uint64_t mSequence;
+    uint64_t mSequence;
     log_time mRealTime;
     char* mMsg;
     union {