Merge changes Iec369a50,I3f9f8d56,I78959464,I72ea858e am: 6ad16cda19 am: 7b45da1006
am: 732f30ee8e
Change-Id: I2aaac98558b8717c7dc339eccaa3215f40c2575a
diff --git a/liblog/include/log/log_time.h b/liblog/include/log/log_time.h
index 5f70f7d..9ece0b3 100644
--- a/liblog/include/log/log_time.h
+++ b/liblog/include/log/log_time.h
@@ -41,13 +41,12 @@
static const uint32_t tv_sec_max = 0xFFFFFFFFUL;
static const uint32_t tv_nsec_max = 999999999UL;
- log_time(const timespec& T) {
- tv_sec = static_cast<uint32_t>(T.tv_sec);
- tv_nsec = static_cast<uint32_t>(T.tv_nsec);
+ log_time(const timespec& T)
+ : tv_sec(static_cast<uint32_t>(T.tv_sec)),
+ tv_nsec(static_cast<uint32_t>(T.tv_nsec)) {
}
- log_time(uint32_t sec, uint32_t nsec) {
- tv_sec = sec;
- tv_nsec = nsec;
+ explicit log_time(uint32_t sec, uint32_t nsec = 0)
+ : tv_sec(sec), tv_nsec(nsec) {
}
#ifdef _SYSTEM_CORE_INCLUDE_PRIVATE_ANDROID_LOGGER_H_
#define __struct_log_time_private_defined
@@ -56,14 +55,14 @@
log_time() {
}
#ifdef __linux__
- log_time(clockid_t id) {
+ explicit log_time(clockid_t id) {
timespec T;
clock_gettime(id, &T);
tv_sec = static_cast<uint32_t>(T.tv_sec);
tv_nsec = static_cast<uint32_t>(T.tv_nsec);
}
#endif
- log_time(const char* T) {
+ explicit log_time(const char* T) {
const uint8_t* c = reinterpret_cast<const uint8_t*>(T);
tv_sec = c[0] | (static_cast<uint32_t>(c[1]) << 8) |
(static_cast<uint32_t>(c[2]) << 16) |
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 8ef9328..4aa2c9f 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -43,6 +43,8 @@
// Default
#define log_buffer_size(id) mMaxSize[id]
+const log_time LogBuffer::pruneMargin(3, 0);
+
void LogBuffer::init() {
log_id_for_each(i) {
mLastSet[i] = false;
@@ -674,6 +676,8 @@
}
times++;
}
+ log_time watermark(log_time::tv_sec_max, log_time::tv_nsec_max);
+ if (oldest) watermark = oldest->mStart - pruneMargin;
LogBufferElementCollection::iterator it;
@@ -695,7 +699,7 @@
mLastSet[id] = true;
}
- if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
+ if (oldest && (watermark <= element->getRealTime())) {
busy = true;
if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
oldest->triggerReader_Locked();
@@ -787,7 +791,7 @@
while (it != mLogElements.end()) {
LogBufferElement* element = *it;
- if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
+ if (oldest && (watermark <= element->getRealTime())) {
busy = true;
if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
oldest->triggerReader_Locked();
@@ -941,7 +945,7 @@
mLastSet[id] = true;
}
- if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
+ if (oldest && (watermark <= element->getRealTime())) {
busy = true;
if (whitelist) {
break;
@@ -985,7 +989,7 @@
mLastSet[id] = true;
}
- if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
+ if (oldest && (watermark <= element->getRealTime())) {
busy = true;
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
@@ -1092,13 +1096,15 @@
// client wants to start from the beginning
it = mLogElements.begin();
} else {
- LogBufferElementCollection::iterator last;
// 3 second limit to continue search for out-of-order entries.
- log_time min = start - log_time(3, 0);
+ log_time min = start - pruneMargin;
+
// Cap to 300 iterations we look back for out-of-order entries.
size_t count = 300;
+
// Client wants to start from some specified time. Chances are
// we are better off starting from the end of the time sorted list.
+ LogBufferElementCollection::iterator last;
for (last = it = mLogElements.end(); it != mLogElements.begin();
/* do nothing */) {
--it;
@@ -1114,9 +1120,22 @@
log_time max = start;
+ LogBufferElement* lastElement = nullptr; // iterator corruption paranoia
+ static const size_t maxSkip = 4194304; // maximum entries to skip
+ size_t skip = maxSkip;
for (; it != mLogElements.end(); ++it) {
LogBufferElement* element = *it;
+ if (!--skip) {
+ android::prdebug("reader.per: too many elements skipped");
+ break;
+ }
+ if (element == lastElement) {
+ android::prdebug("reader.per: identical elements");
+ break;
+ }
+ lastElement = element;
+
if (!privileged && (element->getUid() != uid)) {
continue;
}
@@ -1161,6 +1180,7 @@
return max;
}
+ skip = maxSkip;
pthread_mutex_lock(&mLogElementsLock);
}
pthread_mutex_unlock(&mLogElementsLock);
diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h
index 19d11cb..1272c20 100644
--- a/logd/LogBuffer.h
+++ b/logd/LogBuffer.h
@@ -174,6 +174,7 @@
private:
static constexpr size_t minPrune = 4;
static constexpr size_t maxPrune = 256;
+ static const log_time pruneMargin;
void maybePrune(log_id_t id);
bool prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT);
diff --git a/logd/tests/logd_test.cpp b/logd/tests/logd_test.cpp
index 88cb67a..a1d154a 100644
--- a/logd/tests/logd_test.cpp
+++ b/logd/tests/logd_test.cpp
@@ -670,8 +670,12 @@
while (--i) {
int fd = socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED,
SOCK_SEQPACKET);
- EXPECT_LT(0, fd);
- if (fd < 0) _exit(fd);
+ int save_errno = errno;
+ if (fd < 0) {
+ fprintf(stderr, "failed to open /dev/socket/logdr %s\n",
+ strerror(save_errno));
+ _exit(fd);
+ }
std::string ask = android::base::StringPrintf(
"dumpAndClose lids=0,1,2,3,4,5 timeout=6 start=%" PRIu32
@@ -723,8 +727,12 @@
// active _or_ inactive during the test.
if (content_timeout) {
log_time msg(msg_timeout.entry.sec, msg_timeout.entry.nsec);
- EXPECT_FALSE(msg < now);
- if (msg < now) _exit(-1);
+ if (msg < now) {
+ fprintf(stderr, "%u.%09u < %u.%09u\n", msg_timeout.entry.sec,
+ msg_timeout.entry.nsec, (unsigned)now.tv_sec,
+ (unsigned)now.tv_nsec);
+ _exit(-1);
+ }
if (msg > now) {
now = msg;
now.tv_sec += 30;