Merge changes Iec369a50,I3f9f8d56,I78959464,I72ea858e am: 6ad16cda19 am: 7b45da1006

am: 732f30ee8e

Change-Id: I2aaac98558b8717c7dc339eccaa3215f40c2575a
This commit is contained in:
Mark Salyzyn 2017-04-18 14:33:57 +00:00 committed by android-build-merger
commit ba83d8366c
4 changed files with 46 additions and 18 deletions

View File

@ -41,13 +41,12 @@ struct log_time {
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 @@ struct log_time {
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) |

View File

@ -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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
}
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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
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 @@ 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->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 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
mLastSet[id] = true;
}
if (oldest && (oldest->mStart <= element->getRealTime().nsec())) {
if (oldest && (watermark <= element->getRealTime())) {
busy = true;
if (whitelist) {
break;
@ -985,7 +989,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
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 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start,
// 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 LogBuffer::flushTo(SocketClient* reader, const log_time& start,
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 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start,
return max;
}
skip = maxSkip;
pthread_mutex_lock(&mLogElementsLock);
}
pthread_mutex_unlock(&mLogElementsLock);

View File

@ -174,6 +174,7 @@ class LogBuffer {
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);

View File

@ -670,8 +670,12 @@ TEST(logd, timeout) {
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 @@ TEST(logd, timeout) {
// 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;