logd: enhance multiple blocking readers performance
logd suffers performance degradation when multiple blocking
readers connect to it. Each time when the writer thread log
new entries, all of the readers are notified regardless of
which log id they are watching.
In this case, only give notification to the readers who are
actually watching new entries' log id. This decreases logd
CPU consumption by skipping unnecessary LogBuffer::flushTo
loops.
Test: liblog-unit-tests, logd-unit-tests & CtsLiblogTestCases
logcat-unit-tests
Test: manual:
1.'logcat –b all' at constant heavy logging load level
2.simultaneously 'logcat –b crash' in another session,
a healthy crash buffer usually keep empty
3.logd CPU consumption doesn't increase after step 2
Change-Id: I4ffc045c9feb7a0998f7e47ae2173f8f6aa28e8a
diff --git a/logd/FlushCommand.cpp b/logd/FlushCommand.cpp
old mode 100644
new mode 100755
index a9edc3e..70ecbe0
--- a/logd/FlushCommand.cpp
+++ b/logd/FlushCommand.cpp
@@ -26,18 +26,6 @@
#include "LogTimes.h"
#include "LogUtils.h"
-FlushCommand::FlushCommand(LogReader& reader, bool nonBlock, unsigned long tail,
- unsigned int logMask, pid_t pid, log_time start,
- uint64_t timeout)
- : mReader(reader),
- mNonBlock(nonBlock),
- mTail(tail),
- mLogMask(logMask),
- mPid(pid),
- mStart(start),
- mTimeout((start != log_time::EPOCH) ? timeout : 0) {
-}
-
// runSocketCommand is called once for every open client on the
// log reader socket. Here we manage and associated the reader
// client tracking and log region locks LastLogTimes list of
@@ -56,6 +44,10 @@
while (it != times.end()) {
entry = (*it);
if (entry->mClient == client) {
+ if (!entry->isWatchingMultiple(mLogMask)) {
+ LogTimeEntry::unlock();
+ return;
+ }
if (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec) {
if (mReader.logbuf().isMonotonic()) {
LogTimeEntry::unlock();
diff --git a/logd/FlushCommand.h b/logd/FlushCommand.h
old mode 100644
new mode 100755
index 7cdd03f..543dfc3
--- a/logd/FlushCommand.h
+++ b/logd/FlushCommand.h
@@ -29,16 +29,36 @@
LogReader& mReader;
bool mNonBlock;
unsigned long mTail;
- unsigned int mLogMask;
+ log_mask_t mLogMask;
pid_t mPid;
log_time mStart;
uint64_t mTimeout;
public:
- explicit FlushCommand(LogReader& mReader, bool nonBlock = false,
- unsigned long tail = -1, unsigned int logMask = -1,
- pid_t pid = 0, log_time start = log_time::EPOCH,
- uint64_t timeout = 0);
+ // for opening a reader
+ explicit FlushCommand(LogReader& reader, bool nonBlock, unsigned long tail,
+ log_mask_t logMask, pid_t pid, log_time start,
+ uint64_t timeout)
+ : mReader(reader),
+ mNonBlock(nonBlock),
+ mTail(tail),
+ mLogMask(logMask),
+ mPid(pid),
+ mStart(start),
+ mTimeout((start != log_time::EPOCH) ? timeout : 0) {
+ }
+
+ // for notification of an update
+ explicit FlushCommand(LogReader& reader, log_mask_t logMask)
+ : mReader(reader),
+ mNonBlock(false),
+ mTail(-1),
+ mLogMask(logMask),
+ mPid(0),
+ mStart(log_time::EPOCH),
+ mTimeout(0) {
+ }
+
virtual void runSocketCommand(SocketClient* client);
static bool hasReadLogs(SocketClient* client);
diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp
old mode 100644
new mode 100755
index cfcbaa5..1d0cc33
--- a/logd/LogAudit.cpp
+++ b/logd/LogAudit.cpp
@@ -365,7 +365,7 @@
: LOGGER_ENTRY_MAX_PAYLOAD;
size_t message_len = str_len + sizeof(android_log_event_string_t);
- bool notify = false;
+ log_mask_t notify = 0;
if (events) { // begin scope for event buffer
uint32_t buffer[(message_len + sizeof(uint32_t) - 1) / sizeof(uint32_t)];
@@ -384,7 +384,7 @@
(message_len <= USHRT_MAX) ? (unsigned short)message_len
: USHRT_MAX);
if (rc >= 0) {
- notify = true;
+ notify |= 1 << LOG_ID_EVENTS;
}
// end scope for event buffer
}
@@ -440,7 +440,7 @@
: USHRT_MAX);
if (rc >= 0) {
- notify = true;
+ notify |= 1 << LOG_ID_MAIN;
}
// end scope for main buffer
}
@@ -449,7 +449,7 @@
free(str);
if (notify) {
- reader->notifyNewLog();
+ reader->notifyNewLog(notify);
if (rc < 0) {
rc = message_len;
}
diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp
old mode 100644
new mode 100755
index a7e7208..7a7ac7d
--- a/logd/LogKlog.cpp
+++ b/logd/LogKlog.cpp
@@ -826,7 +826,7 @@
// notify readers
if (!rc) {
- reader->notifyNewLog();
+ reader->notifyNewLog(static_cast<log_mask_t>(1 << LOG_ID_KERNEL));
}
return rc;
diff --git a/logd/LogListener.cpp b/logd/LogListener.cpp
old mode 100644
new mode 100755
index fcf2cd8..fc51dcf
--- a/logd/LogListener.cpp
+++ b/logd/LogListener.cpp
@@ -94,12 +94,13 @@
android_log_header_t* header =
reinterpret_cast<android_log_header_t*>(buffer);
- if (/* header->id < LOG_ID_MIN || */ header->id >= LOG_ID_MAX ||
- header->id == LOG_ID_KERNEL) {
+ log_id_t logId = static_cast<log_id_t>(header->id);
+ if (/* logId < LOG_ID_MIN || */ logId >= LOG_ID_MAX ||
+ logId == LOG_ID_KERNEL) {
return false;
}
- if ((header->id == LOG_ID_SECURITY) &&
+ if ((logId == LOG_ID_SECURITY) &&
(!__android_log_security() ||
!clientHasLogCredentials(cred->uid, cred->gid, cred->pid))) {
return false;
@@ -134,11 +135,10 @@
if (logbuf != nullptr) {
int res = logbuf->log(
- (log_id_t)header->id, header->realtime, cred->uid, cred->pid,
- header->tid, msg,
+ logId, header->realtime, cred->uid, cred->pid, header->tid, msg,
((size_t)n <= USHRT_MAX) ? (unsigned short)n : USHRT_MAX);
if (res > 0 && reader != nullptr) {
- reader->notifyNewLog();
+ reader->notifyNewLog(static_cast<log_mask_t>(1 << logId));
}
}
diff --git a/logd/LogReader.cpp b/logd/LogReader.cpp
old mode 100644
new mode 100755
index 6d69316..2b6556d
--- a/logd/LogReader.cpp
+++ b/logd/LogReader.cpp
@@ -35,9 +35,9 @@
}
// When we are notified a new log entry is available, inform
-// all of our listening sockets.
-void LogReader::notifyNewLog() {
- FlushCommand command(*this);
+// listening sockets who are watching this entry's log id.
+void LogReader::notifyNewLog(log_mask_t logMask) {
+ FlushCommand command(*this, logMask);
runOnEachSocket(&command);
}
diff --git a/logd/LogReader.h b/logd/LogReader.h
old mode 100644
new mode 100755
index 271e08c..b5312b6
--- a/logd/LogReader.h
+++ b/logd/LogReader.h
@@ -19,6 +19,8 @@
#include <sysutils/SocketListener.h>
+#include "LogTimes.h"
+
#define LOGD_SNDTIMEO 32
class LogBuffer;
@@ -28,7 +30,7 @@
public:
explicit LogReader(LogBuffer* logbuf);
- void notifyNewLog();
+ void notifyNewLog(log_mask_t logMask);
LogBuffer& logbuf(void) const {
return mLogbuf;
diff --git a/logd/LogTimes.cpp b/logd/LogTimes.cpp
old mode 100644
new mode 100755
index 25c2ad2..7a6f84b
--- a/logd/LogTimes.cpp
+++ b/logd/LogTimes.cpp
@@ -28,9 +28,8 @@
pthread_mutex_t LogTimeEntry::timesLock = PTHREAD_MUTEX_INITIALIZER;
LogTimeEntry::LogTimeEntry(LogReader& reader, SocketClient* client,
- bool nonBlock, unsigned long tail,
- unsigned int logMask, pid_t pid, log_time start,
- uint64_t timeout)
+ bool nonBlock, unsigned long tail, log_mask_t logMask,
+ pid_t pid, log_time start, uint64_t timeout)
: mRefCount(1),
mRelease(false),
mError(false),
diff --git a/logd/LogTimes.h b/logd/LogTimes.h
old mode 100644
new mode 100755
index 9ca2aea..76d016c
--- a/logd/LogTimes.h
+++ b/logd/LogTimes.h
@@ -26,6 +26,8 @@
#include <log/log.h>
#include <sysutils/SocketClient.h>
+typedef unsigned int log_mask_t;
+
class LogReader;
class LogBufferElement;
@@ -41,7 +43,7 @@
LogReader& mReader;
static void* threadStart(void* me);
static void threadStop(void* me);
- const unsigned int mLogMask;
+ const log_mask_t mLogMask;
const pid_t mPid;
unsigned int skipAhead[LOG_ID_MAX];
pid_t mLastTid[LOG_ID_MAX];
@@ -51,7 +53,7 @@
public:
LogTimeEntry(LogReader& reader, SocketClient* client, bool nonBlock,
- unsigned long tail, unsigned int logMask, pid_t pid,
+ unsigned long tail, log_mask_t logMask, pid_t pid,
log_time start, uint64_t timeout);
SocketClient* mClient;
@@ -133,8 +135,11 @@
// No one else is holding a reference to this
delete this;
}
- bool isWatching(log_id_t id) {
- return (mLogMask & (1 << id)) != 0;
+ bool isWatching(log_id_t id) const {
+ return mLogMask & (1 << id);
+ }
+ bool isWatchingMultiple(log_mask_t logMask) const {
+ return mLogMask & logMask;
}
// flushTo filter callbacks
static int FilterFirstPass(const LogBufferElement* element, void* me);