logd: don't poll() before recvmsg()
LogListener uses the libsysutils SocketListener class to read incoming
log messages, which means that it poll()'s to wait for new data then
calls recvmsg() when this data is available. That is unnecessary,
since this is a blocking socket, it already has a dedicated thread,
and we're not using any other SocketListner features, so a tight loop
of recvmsg() is sufficient.
Below are the stats from simpleperf during a framework restart. To
get an apples to apples comparison, these stats calculate the overhead
of receiving the message as 1 - (<number of perf events dispatching
the logs in logd>/<total number of perf events for the listener thread>).
With SocketListener / poll()
378563153 total events for the listener thread - SocketListener::runListener()
245799364 events for reading and dispatching logs + recvmsg() - LogListener::onDataAvailable()
67622952 events for recvmsg() inside LogListener::onDataAvailable()
=> (378563153 - 245799364) = 132763789 SocketListener + poll() overhead
=> (132763789 + 67622952) = 200386741 total overhead to for recvmsg() + poll() + SocketListener
=> (200386741 / 378563153) = 52.9% overhead to read each log message.
Without SocketListener / poll()
324802401 total events for the new listener thread - LogListener::ThreadFunction()
133208105 events for recvmsg()
=> (133208105 / 324802401) = 41% overhead to read each log message.
This shows a 22.5% = (41 - 52.9)/52.9 reduction in cost spent for each log message.
Test: logging unit tests
Test: simpleperf
Change-Id: I1f93b7a06fac6adce8e64e727bf6d8c5935c77c9
diff --git a/logd/LogListener.cpp b/logd/LogListener.cpp
index 138ab28..fbe6ea0 100644
--- a/logd/LogListener.cpp
+++ b/logd/LogListener.cpp
@@ -22,6 +22,8 @@
#include <sys/un.h>
#include <unistd.h>
+#include <thread>
+
#include <cutils/sockets.h>
#include <private/android_filesystem_config.h>
#include <private/android_logger.h>
@@ -31,33 +33,47 @@
#include "LogUtils.h"
LogListener::LogListener(LogBuffer* buf, LogReader* reader)
- : SocketListener(getLogSocket(), false), logbuf(buf), reader(reader) {}
+ : socket_(GetLogSocket()), logbuf_(buf), reader_(reader) {}
-bool LogListener::onDataAvailable(SocketClient* cli) {
+bool LogListener::StartListener() {
+ if (socket_ <= 0) {
+ return false;
+ }
+ auto thread = std::thread(&LogListener::ThreadFunction, this);
+ thread.detach();
+ return true;
+}
+
+void LogListener::ThreadFunction() {
static bool name_set;
if (!name_set) {
prctl(PR_SET_NAME, "logd.writer");
name_set = true;
}
+ while (true) {
+ HandleData();
+ }
+}
+
+void LogListener::HandleData() {
// + 1 to ensure null terminator if MAX_PAYLOAD buffer is received
- char buffer[sizeof(android_log_header_t) + LOGGER_ENTRY_MAX_PAYLOAD + 1];
- struct iovec iov = { buffer, sizeof(buffer) - 1 };
+ __attribute__((uninitialized)) char
+ buffer[sizeof(android_log_header_t) + LOGGER_ENTRY_MAX_PAYLOAD + 1];
+ struct iovec iov = {buffer, sizeof(buffer) - 1};
alignas(4) char control[CMSG_SPACE(sizeof(struct ucred))];
struct msghdr hdr = {
nullptr, 0, &iov, 1, control, sizeof(control), 0,
};
- int socket = cli->getSocket();
-
// To clear the entire buffer is secure/safe, but this contributes to 1.68%
// overhead under logging load. We are safe because we check counts, but
// still need to clear null terminator
// memset(buffer, 0, sizeof(buffer));
- ssize_t n = recvmsg(socket, &hdr, 0);
+ ssize_t n = recvmsg(socket_, &hdr, 0);
if (n <= (ssize_t)(sizeof(android_log_header_t))) {
- return false;
+ return;
}
buffer[n] = 0;
@@ -75,14 +91,14 @@
}
if (cred == nullptr) {
- return false;
+ return;
}
if (cred->uid == AID_LOGD) {
// ignore log messages we send to ourself.
// Such log messages are often generated by libraries we depend on
// which use standard Android logging.
- return false;
+ return;
}
android_log_header_t* header =
@@ -90,13 +106,13 @@
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;
+ return;
}
if ((logId == LOG_ID_SECURITY) &&
(!__android_log_security() ||
!clientHasLogCredentials(cred->uid, cred->gid, cred->pid))) {
- return false;
+ return;
}
char* msg = ((char*)buffer) + sizeof(android_log_header_t);
@@ -105,16 +121,16 @@
// NB: hdr.msg_flags & MSG_TRUNC is not tested, silently passing a
// truncated message to the logs.
- int res = logbuf->log(logId, header->realtime, cred->uid, cred->pid, header->tid, msg,
- ((size_t)n <= UINT16_MAX) ? (uint16_t)n : UINT16_MAX);
+ int res = logbuf_->log(logId, header->realtime, cred->uid, cred->pid, header->tid, msg,
+ ((size_t)n <= UINT16_MAX) ? (uint16_t)n : UINT16_MAX);
if (res > 0) {
- reader->notifyNewLog(static_cast<unsigned int>(1 << logId));
+ reader_->notifyNewLog(static_cast<unsigned int>(1 << logId));
}
- return true;
+ return;
}
-int LogListener::getLogSocket() {
+int LogListener::GetLogSocket() {
static const char socketName[] = "logdw";
int sock = android_get_control_socket(socketName);
diff --git a/logd/LogListener.h b/logd/LogListener.h
index 8fe3da4..ce3e0f2 100644
--- a/logd/LogListener.h
+++ b/logd/LogListener.h
@@ -14,24 +14,22 @@
* limitations under the License.
*/
-#ifndef _LOGD_LOG_LISTENER_H__
-#define _LOGD_LOG_LISTENER_H__
+#pragma once
-#include <sysutils/SocketListener.h>
+#include "LogBuffer.h"
#include "LogReader.h"
-class LogListener : public SocketListener {
- LogBuffer* logbuf;
- LogReader* reader;
+class LogListener {
+ public:
+ LogListener(LogBuffer* buf, LogReader* reader);
+ bool StartListener();
- public:
- LogListener(LogBuffer* buf, LogReader* reader);
+ private:
+ void ThreadFunction();
+ void HandleData();
+ static int GetLogSocket();
- protected:
- virtual bool onDataAvailable(SocketClient* cli);
-
- private:
- static int getLogSocket();
+ int socket_;
+ LogBuffer* logbuf_;
+ LogReader* reader_;
};
-
-#endif
diff --git a/logd/main.cpp b/logd/main.cpp
index cc45eb3..13f853c 100644
--- a/logd/main.cpp
+++ b/logd/main.cpp
@@ -323,8 +323,7 @@
// and LogReader is notified to send updates to connected clients.
LogListener* swl = new LogListener(logBuf, reader);
- // Backlog and /proc/sys/net/unix/max_dgram_qlen set to large value
- if (swl->startListener(600)) {
+ if (!swl->StartListener()) {
return EXIT_FAILURE;
}