Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit c64dd8e7 authored by Tom Cherry's avatar Tom Cherry
Browse files

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
parent 72fdec17

logd/LogListener.cpp

+33 −17
Original line number Diff line number Diff line
@@ -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,17 +33,33 @@ 
#include "LogUtils.h"



LogListener::LogListener(LogBuffer* buf, LogReader* reader)

    : SocketListener(getLogSocket(), false), logbuf(buf), reader(reader) {}

    : socket_(GetLogSocket()), logbuf_(buf), reader_(reader) {}



bool LogListener::StartListener() {

    if (socket_ <= 0) {

        return false;

    }

    auto thread = std::thread(&LogListener::ThreadFunction, this);

    thread.detach();

    return true;

}



bool LogListener::onDataAvailable(SocketClient* cli) {

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];

    __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))];
@@ -49,15 +67,13 @@ bool LogListener::onDataAvailable(SocketClient* cli) { 
        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 @@ bool LogListener::onDataAvailable(SocketClient* cli) { 
    }



    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 @@ bool LogListener::onDataAvailable(SocketClient* cli) { 
    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 @@ bool LogListener::onDataAvailable(SocketClient* cli) { 
    // 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,

    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);

logd/LogListener.h

+13 −15
Original line number Diff line number Diff line
@@ -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);



   protected:

    virtual bool onDataAvailable(SocketClient* cli);

    bool StartListener();



  private:

    static int getLogSocket();

};

    void ThreadFunction();

    void HandleData();

    static int GetLogSocket();



#endif
 
    int socket_;

    LogBuffer* logbuf_;

    LogReader* reader_;

};

logd/main.cpp

+1 −2
Original line number Diff line number Diff line
@@ -323,8 +323,7 @@ int main(int argc, char* argv[]) { 
    // 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;

    }