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

Commit 79d54f78 authored by Tom Cherry's avatar Tom Cherry
Browse files

logd: remove FlushCommand 

This code has evolved to the point that it LogReader::notifyNewLog()
executes FlushCommand on every socket.  FlushCommand then iterates
over all log reader threads in LogTimes and flushes triggers them to
flush logs if they match the client.  This can be simplified to simply
looping over all of the reads in LogTimes.

Code readability was the primary motivation here, but note that 64% of
LogReader::notifyNewLog() was spent looping over the sockets, and an
additional 78% of FlushCommand::runSocketCommand() was spent
repeatedly locking and unlocking the LogTimes lock.

Overall, this reduces the cost of LogReader::notifyNewLog() in
LogListener::onDataAvailable() from 5.91% to 2.93%.  This is the
critical path for handling incoming log messages, so it's a
non-trivial savings.

Test: logging unit tests
Test: unprivileged clients still cannot view privileged logs
Change-Id: Ic7620978a6c23e5e2cb179ff0c42b7cea52fc011
parent 20118eec

logd/Android.bp

+0 −1
Original line number Diff line number Diff line
@@ -36,7 +36,6 @@ cc_library_static { 
        "CommandListener.cpp",

        "LogListener.cpp",

        "LogReader.cpp",

        "FlushCommand.cpp",

        "LogBuffer.cpp",

        "LogBufferElement.cpp",

        "LogTimes.cpp",

logd/FlushCommand.cpp

deleted100644 → 0
+0 −75
Original line number Diff line number Diff line 
/*

 * Copyright (C) 2012-2014 The Android Open Source Project

 *

 * Licensed under the Apache License, Version 2.0 (the "License");

 * you may not use this file except in compliance with the License.

 * You may obtain a copy of the License at

 *

 *      http://www.apache.org/licenses/LICENSE-2.0

 *

 * Unless required by applicable law or agreed to in writing, software

 * distributed under the License is distributed on an "AS IS" BASIS,

 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

 * See the License for the specific language governing permissions and

 * limitations under the License.

 */



#include <stdlib.h>



#include <private/android_filesystem_config.h>



#include "FlushCommand.h"

#include "LogBuffer.h"

#include "LogBufferElement.h"

#include "LogCommand.h"

#include "LogReader.h"

#include "LogTimes.h"

#include "LogUtils.h"



// 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

// LogTimeEntrys, and spawn a transitory per-client thread to

// work at filing data to the  socket.

//

// global LogTimeEntry::wrlock() is used to protect access,

// reference counts are used to ensure that individual

// LogTimeEntry lifetime is managed when not protected.

void FlushCommand::runSocketCommand(SocketClient* client) {

    LogTimeEntry* entry = nullptr;

    LastLogTimes& times = mReader.logbuf().mTimes;



    LogTimeEntry::wrlock();

    LastLogTimes::iterator it = times.begin();

    while (it != times.end()) {

        entry = it->get();

        if (entry->mClient == client) {

            if (!entry->isWatchingMultiple(mLogMask)) {

                LogTimeEntry::unlock();

                return;

            }

            if (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec) {

                LogTimeEntry::unlock();

                return;

            }

            entry->triggerReader_Locked();

            LogTimeEntry::unlock();

            return;

        }

        it++;

    }



    LogTimeEntry::unlock();

}



bool FlushCommand::hasReadLogs(SocketClient* client) {

    return clientHasLogCredentials(client);

}



static bool clientHasSecurityCredentials(SocketClient* client) {

    return (client->getUid() == AID_SYSTEM) || (client->getGid() == AID_SYSTEM);

}



bool FlushCommand::hasSecurityLogs(SocketClient* client) {

    return clientHasSecurityCredentials(client);

}

logd/FlushCommand.h

deleted100644 → 0
+0 −43
Original line number Diff line number Diff line 
/*

 * Copyright (C) 2012-2013 The Android Open Source Project

 *

 * Licensed under the Apache License, Version 2.0 (the "License");

 * you may not use this file except in compliance with the License.

 * You may obtain a copy of the License at

 *

 *      http://www.apache.org/licenses/LICENSE-2.0

 *

 * Unless required by applicable law or agreed to in writing, software

 * distributed under the License is distributed on an "AS IS" BASIS,

 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

 * See the License for the specific language governing permissions and

 * limitations under the License.

 */

#ifndef _FLUSH_COMMAND_H

#define _FLUSH_COMMAND_H



#include <android/log.h>

#include <sysutils/SocketClientCommand.h>



class LogBufferElement;



#include "LogTimes.h"



class LogReader;



class FlushCommand : public SocketClientCommand {

    LogReader& mReader;

    log_mask_t mLogMask;



   public:

    explicit FlushCommand(LogReader& reader, log_mask_t logMask)

        : mReader(reader), mLogMask(logMask) {

    }



    virtual void runSocketCommand(SocketClient* client);



    static bool hasReadLogs(SocketClient* client);

    static bool hasSecurityLogs(SocketClient* client);

};



#endif

logd/LogReader.cpp

+23 −7
Original line number Diff line number Diff line
@@ -24,21 +24,35 @@ 
#include <cutils/sockets.h>

#include <private/android_logger.h>



#include "FlushCommand.h"

#include "LogBuffer.h"

#include "LogBufferElement.h"

#include "LogReader.h"

#include "LogUtils.h"



static bool CanReadSecurityLogs(SocketClient* client) {

    return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM;

}



LogReader::LogReader(LogBuffer* logbuf)

    : SocketListener(getLogSocket(), true), mLogbuf(*logbuf) {

}



// When we are notified a new log entry is available, inform

// listening sockets who are watching this entry's log id.

void LogReader::notifyNewLog(log_mask_t logMask) {

    FlushCommand command(*this, logMask);

    runOnEachSocket(&command);

void LogReader::notifyNewLog(log_mask_t log_mask) {

    LastLogTimes& times = mLogbuf.mTimes;



    LogTimeEntry::wrlock();

    for (const auto& entry : times) {

        if (!entry->isWatchingMultiple(log_mask)) {

            continue;

        }

        if (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec) {

            continue;

        }

        entry->triggerReader_Locked();

    }

    LogTimeEntry::unlock();

}



// Note returning false will release the SocketClient instance.
@@ -129,6 +143,9 @@ bool LogReader::onDataAvailable(SocketClient* cli) { 
        nonBlock = true;

    }



    bool privileged = clientHasLogCredentials(cli);

    bool can_read_security = CanReadSecurityLogs(cli);



    uint64_t sequence = 1;

    // Convert realtime to sequence number

    if (start != log_time::EPOCH) {
@@ -178,8 +195,7 @@ bool LogReader::onDataAvailable(SocketClient* cli) { 
        } logFindStart(logMask, pid, start, sequence,

                       logbuf().isMonotonic() && android::isMonotonic(start));



        logbuf().flushTo(cli, sequence, nullptr, FlushCommand::hasReadLogs(cli),

                         FlushCommand::hasSecurityLogs(cli),

        logbuf().flushTo(cli, sequence, nullptr, privileged, can_read_security,

                         logFindStart.callback, &logFindStart);



        if (!logFindStart.found()) {
@@ -203,7 +219,7 @@ bool LogReader::onDataAvailable(SocketClient* cli) { 


    LogTimeEntry::wrlock();

    auto entry = std::make_unique<LogTimeEntry>(*this, cli, nonBlock, tail, logMask, pid, start,

                                                sequence, timeout);

                                                sequence, timeout, privileged, can_read_security);

    if (!entry->startReader_Locked()) {

        LogTimeEntry::unlock();

        return false;

logd/LogTimes.cpp

+8 −9
Original line number Diff line number Diff line
@@ -18,7 +18,6 @@ 
#include <string.h>

#include <sys/prctl.h>



#include "FlushCommand.h"

#include "LogBuffer.h"

#include "LogReader.h"

#include "LogTimes.h"
@@ -27,7 +26,8 @@ pthread_mutex_t LogTimeEntry::timesLock = PTHREAD_MUTEX_INITIALIZER; 


LogTimeEntry::LogTimeEntry(LogReader& reader, SocketClient* client, bool nonBlock,

                           unsigned long tail, log_mask_t logMask, pid_t pid, log_time start_time,

                           uint64_t start, uint64_t timeout)

                           uint64_t start, uint64_t timeout, bool privileged,

                           bool can_read_security_logs)

    : leadingDropped(false),

      mReader(reader),

      mLogMask(logMask),
@@ -38,7 +38,9 @@ LogTimeEntry::LogTimeEntry(LogReader& reader, SocketClient* client, bool nonBloc 
      mClient(client),

      mStartTime(start_time),

      mStart(start),

      mNonBlock(nonBlock) {

      mNonBlock(nonBlock),

      privileged_(privileged),

      can_read_security_logs_(can_read_security_logs) {

    mTimeout.tv_sec = timeout / NS_PER_SEC;

    mTimeout.tv_nsec = timeout % NS_PER_SEC;

    memset(mLastTid, 0, sizeof(mLastTid));
@@ -72,9 +74,6 @@ void* LogTimeEntry::threadStart(void* obj) { 


    LogBuffer& logbuf = me->mReader.logbuf();



    bool privileged = FlushCommand::hasReadLogs(client);

    bool security = FlushCommand::hasSecurityLogs(client);



    me->leadingDropped = true;



    wrlock();
@@ -96,12 +95,12 @@ void* LogTimeEntry::threadStart(void* obj) { 
        unlock();



        if (me->mTail) {

            logbuf.flushTo(client, start, nullptr, privileged, security,

            logbuf.flushTo(client, start, nullptr, me->privileged_, me->can_read_security_logs_,

                           FilterFirstPass, me);

            me->leadingDropped = true;

        }

        start = logbuf.flushTo(client, start, me->mLastTid, privileged,

                               security, FilterSecondPass, me);

        start = logbuf.flushTo(client, start, me->mLastTid, me->privileged_,

                               me->can_read_security_logs_, FilterSecondPass, me);



        // We only ignore entries before the original start time for the first flushTo(), if we

        // get entries after this first flush before the original start time, then the client