Merge changes I2a073293,Ia55ef8b9,I79a385fc am: 82b5c619b8 am: 5a0afe7d27

am: 9f8a97ed0b

Change-Id: Iae26c69eb4ffdfdc3b20b1a841bfc67d768f33f1

1 files changed, 35 insertions, 27 deletions

diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 60d647d77..f67372a86 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -183,7 +183,7 @@ static enum match_type identical(LogBufferElement* elem,
     lenr -= avcr - msgr;
     if (lenl != lenr) return DIFFERENT;
     // TODO: After b/35468874 is addressed, revisit "lenl > strlen(avc)"
-    // condition, it might become superflous.
+    // condition, it might become superfluous.
     if (lenl > strlen(avc) &&
         fastcmp<memcmp>(avcl + strlen(avc), avcr + strlen(avc),
                         lenl - strlen(avc))) {
@@ -376,18 +376,12 @@ 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;
+        log_time end = log_time::EPOCH;
         bool end_set = false;
         bool end_always = false;
 
@@ -401,6 +395,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;
@@ -409,12 +404,20 @@ void LogBuffer::log(LogBufferElement* elem) {
             times++;
         }
 
-        if (end_always || (end_set && (end >= (*last)->getSequence()))) {
+        if (end_always || (end_set && (end > (*it)->getRealTime()))) {
             mLogElements.push_back(elem);
         } else {
+            // should be short as timestamps are localized near end()
+            do {
+                last = it;
+                if (__predict_false(it == mLogElements.begin())) {
+                    break;
+                }
+                --it;
+            } while (((*it)->getRealTime() > elem->getRealTime()) &&
+                     (!end_set || (end <= (*it)->getRealTime())));
             mLogElements.insert(last, elem);
         }
-
         LogTimeEntry::unlock();
     }
 
@@ -589,12 +592,12 @@ class LogBufferElementLast {
     }
 
     void clear(LogBufferElement* element) {
-        uint64_t current =
-            element->getRealTime().nsec() - (EXPIRE_RATELIMIT * NS_PER_SEC);
+        log_time current =
+            element->getRealTime() - log_time(EXPIRE_RATELIMIT, 0);
         for (LogBufferElementMap::iterator it = map.begin(); it != map.end();) {
             LogBufferElement* mapElement = it->second;
             if ((mapElement->getDropped() >= EXPIRE_THRESHOLD) &&
-                (current > mapElement->getRealTime().nsec())) {
+                (current > mapElement->getRealTime())) {
                 it = map.erase(it);
             } else {
                 ++it;
@@ -690,7 +693,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
                 mLastSet[id] = true;
             }
 
-            if (oldest && (oldest->mStart <= element->getSequence())) {
+            if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
                 busy = true;
                 if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
                     oldest->triggerReader_Locked();
@@ -782,7 +785,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
         while (it != mLogElements.end()) {
             LogBufferElement* element = *it;
 
-            if (oldest && (oldest->mStart <= element->getSequence())) {
+            if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
                 busy = true;
                 if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
                     oldest->triggerReader_Locked();
@@ -936,7 +939,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             mLastSet[id] = true;
         }
 
-        if (oldest && (oldest->mStart <= element->getSequence())) {
+        if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
             busy = true;
             if (whitelist) {
                 break;
@@ -980,7 +983,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
                 mLastSet[id] = true;
             }
 
-            if (oldest && (oldest->mStart <= element->getSequence())) {
+            if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
                 busy = true;
                 if (stats.sizes(id) > (2 * log_buffer_size(id))) {
                     // kick a misbehaving log reader client off the island
@@ -1073,32 +1076,37 @@ unsigned long LogBuffer::getSize(log_id_t id) {
     return retval;
 }
 
-uint64_t LogBuffer::flushTo(
-    SocketClient* reader, const uint64_t start, bool privileged, bool security,
+log_time LogBuffer::flushTo(
+    SocketClient* reader, const log_time& start, bool privileged, bool security,
     int (*filter)(const LogBufferElement* element, void* arg), void* arg) {
     LogBufferElementCollection::iterator it;
-    uint64_t max = start;
     uid_t uid = reader->getUid();
 
     pthread_mutex_lock(&mLogElementsLock);
 
-    if (start <= 1) {
+    if (start == log_time::EPOCH) {
         // client wants to start from the beginning
         it = mLogElements.begin();
     } else {
+        LogBufferElementCollection::iterator last = mLogElements.begin();
+        // 30 second limit to continue search for out-of-order entries.
+        log_time min = start - log_time(30, 0);
         // Client wants to start from some specified time. Chances are
         // we are better off starting from the end of the time sorted list.
         for (it = mLogElements.end(); it != mLogElements.begin();
              /* do nothing */) {
             --it;
             LogBufferElement* element = *it;
-            if (element->getSequence() <= start) {
-                it++;
+            if (element->getRealTime() > start) {
+                last = it;
+            } else if (element->getRealTime() < min) {
                 break;
             }
         }
+        it = last;
     }
 
+    log_time max = start;
     // Help detect if the valid message before is from the same source so
     // we can differentiate chatty filter types.
     pid_t lastTid[LOG_ID_MAX] = { 0 };
@@ -1114,7 +1122,7 @@ uint64_t LogBuffer::flushTo(
             continue;
         }
 
-        if (element->getSequence() <= start) {
+        if (element->getRealTime() <= start) {
             continue;
         }