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
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 2b6c276..fbd04ef 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 @@
// 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 @@
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 @@
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 43990e8..90756dd 100644
--- a/logd/LogBufferElement.h
+++ b/logd/LogBufferElement.h
@@ -40,7 +40,7 @@
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 {