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

Commit 6ad16cda authored by Mark Salyzyn's avatar Mark Salyzyn Committed by Gerrit Code Review
Browse files

Merge changes Iec369a50,I3f9f8d56,I78959464,I72ea858e 

* changes:
  logd: instrument tests better for failure
  liblog: log_time add explicit to some constructors.
  logd: iterator corruption paranoia
  logd: regression in handling watermark boundary.
parents ffa38cfc 24aa9a41

liblog/include/log/log_time.h

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

logd/LogBuffer.cpp

+26 −6
Original line number Diff line number Diff line
@@ -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;
@@ -672,6 +674,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;
@@ -693,7 +697,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();
@@ -785,7 +789,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();
@@ -939,7 +943,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;
@@ -983,7 +987,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
@@ -1090,13 +1094,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;
@@ -1112,9 +1118,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;

        }
@@ -1159,6 +1178,7 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start, 
            return max;

        }



        skip = maxSkip;

        pthread_mutex_lock(&mLogElementsLock);

    }

    pthread_mutex_unlock(&mLogElementsLock);

logd/LogBuffer.h

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

logd/tests/logd_test.cpp

+12 −4
Original line number Diff line number Diff line
@@ -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;