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

Commit 903156dd authored by Mark Salyzyn's avatar Mark Salyzyn
Browse files

logd: add Chattiest LOG_TAG statistics 

Report global LOG_TAG usage.

Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-tests
Test: manual: inspect logcat -S results around 'Chattiest TAGs'
Bug: 37254265
Change-Id: I32473a1d9131c87e4fb7841d5cc0ea9cc14c63cd
parent a42ec8a9

logd/LogStatistics.cpp

+79 −0
Original line number Diff line number Diff line
@@ -32,6 +32,7 @@ static const uint64_t hourSec = 60 * 60; 
static const uint64_t monthSec = 31 * 24 * hourSec;



size_t LogStatistics::SizesTotal;

size_t TagNameEntry::droppedElsewhere;



LogStatistics::LogStatistics() : enable(false) {

    log_time now(CLOCK_REALTIME);
@@ -152,6 +153,8 @@ void LogStatistics::add(LogBufferElement* element) { 
            tagTable.add(tag, element);

        }

    }



    tagNameTable.add(TagNameEntry(element).getKey(), element);

}



void LogStatistics::subtract(LogBufferElement* element) {
@@ -191,6 +194,8 @@ void LogStatistics::subtract(LogBufferElement* element) { 
            tagTable.subtract(tag, element);

        }

    }



    tagNameTable.subtract(TagNameEntry(element).getKey(), element);

}



// Atomically set an entry to drop
@@ -225,6 +230,8 @@ void LogStatistics::drop(LogBufferElement* element) { 
            tagTable.drop(tag, element);

        }

    }



    tagNameTable.drop(TagNameEntry(element).getKey(), element);

}



// caller must own and free character string
@@ -505,6 +512,71 @@ std::string TagEntry::format(const LogStatistics& /* stat */, 
    return formatLine(name, size, pruned);

}



std::string TagNameEntry::formatHeader(const std::string& name,

                                       log_id_t /* id */) const {

    return formatLine(name, std::string("Size"), std::string("Prune")) +

           formatLine(std::string("  TID/PID/UID   LOG_TAG NAME"),

                      std::string("BYTES"), std::string("NUM"));

}



std::string TagNameEntry::format(const LogStatistics& /* stat */,

                                 log_id_t /* id */) const {

    std::string name;

    pid_t tid = getTid();

    pid_t pid = getPid();

    std::string pidstr;

    if (pid != (pid_t)-1) {

        pidstr = android::base::StringPrintf("%u", pid);

        if ((tid != (pid_t)-1) && (tid != pid)) pidstr = "/" + pidstr;

    }

    int len = 9 - pidstr.length();

    if (len < 0) len = 0;

    if ((tid == (pid_t)-1) || (tid == pid)) {

        name = android::base::StringPrintf("%*s", len, "");

    } else {

        name = android::base::StringPrintf("%*u", len, tid);

    }

    name += pidstr;

    uid_t uid = getUid();

    if (uid != (uid_t)-1) {

        name += android::base::StringPrintf("/%u", uid);

    }



    std::string size = android::base::StringPrintf("%zu", getSizes());



    const char* nameTmp = getName();

    if (nameTmp) {

        size_t lenSpace = std::max(16 - name.length(), (size_t)1);

        size_t len = EntryBaseConstants::total_len -

                     EntryBaseConstants::pruned_len - size.length() -

                     name.length() - lenSpace - 2;

        size_t lenNameTmp = strlen(nameTmp);

        while ((len < lenNameTmp) && (lenSpace > 1)) {

            ++len;

            --lenSpace;

        }

        name += android::base::StringPrintf("%*s", (int)lenSpace, "");

        if (len < lenNameTmp) {

            name += "...";

            nameTmp += lenNameTmp - std::max(len - 3, (size_t)1);

        }

        name += nameTmp;

    }



    std::string pruned = "";



    // Because of TagNameEntry::droppedElsewhere, dropped count can get

    // modified for "chatty" tags.  Since the size is always zero this

    // modification is a "can not happen".

    TagNameEntry& me = const_cast<TagNameEntry&>(*this);

    size_t dropped = me.getDropped();

    if (dropped) {

        pruned = android::base::StringPrintf("%zu", dropped);

    }



    return formatLine(name, size, pruned);

}



static std::string formatMsec(uint64_t val) {

    static const unsigned subsecDigits = 3;

    static const uint64_t sec = MS_PER_SEC;
@@ -725,6 +797,13 @@ std::string LogStatistics::format(uid_t uid, pid_t pid, 
        output += tidTable.format(*this, uid, pid, name);

    }



    if (enable) {

        name = "Chattiest TAGs";

        if (pid) name += android::base::StringPrintf(" for PID %d", pid);

        name += ":";

        output += tagNameTable.format(*this, uid, pid, name);

    }



    if (enable && (logMask & (1 << LOG_ID_EVENTS))) {

        name = "Chattiest events log buffer TAGs";

        if (pid) name += android::base::StringPrintf(" for PID %d", pid);

logd/LogStatistics.h

+151 −5
Original line number Diff line number Diff line
@@ -18,10 +18,14 @@ 
#define _LOGD_LOG_STATISTICS_H__



#include <ctype.h>

#include <inttypes.h>

#include <stdint.h>

#include <stdlib.h>

#include <string.h>

#include <sys/types.h>



#include <algorithm>  // std::max

#include <experimental/string_view>

#include <memory>

#include <string>  // std::string

#include <unordered_map>
@@ -77,7 +81,7 @@ class LogHashtable { 
    std::unique_ptr<const TEntry* []> sort(uid_t uid, pid_t pid,

                                           size_t len) const {

        if (!len) {

            std::unique_ptr<const TEntry* []> sorted(NULL);

            std::unique_ptr<const TEntry* []> sorted(nullptr);

            return sorted;

        }
@@ -318,7 +322,7 @@ struct PidEntry : public EntryBaseDropped { 
        : EntryBaseDropped(element),

          pid(element.pid),

          uid(element.uid),

          name(element.name ? strdup(element.name) : NULL) {

          name(element.name ? strdup(element.name) : nullptr) {

    }

    ~PidEntry() {

        free(name);
@@ -340,7 +344,7 @@ struct PidEntry : public EntryBaseDropped { 
    inline void add(pid_t newPid) {

        if (name && !fastcmp<strncmp>(name, "zygote", 6)) {

            free(name);

            name = NULL;

            name = nullptr;

        }

        if (!name) {

            name = android::pidToName(newPid);
@@ -388,7 +392,7 @@ struct TidEntry : public EntryBaseDropped { 
          tid(element.tid),

          pid(element.pid),

          uid(element.uid),

          name(element.name ? strdup(element.name) : NULL) {

          name(element.name ? strdup(element.name) : nullptr) {

    }

    ~TidEntry() {

        free(name);
@@ -413,7 +417,7 @@ struct TidEntry : public EntryBaseDropped { 
    inline void add(pid_t incomingTid) {

        if (name && !fastcmp<strncmp>(name, "zygote", 6)) {

            free(name);

            name = NULL;

            name = nullptr;

        }

        if (!name) {

            name = android::tidToName(incomingTid);
@@ -477,6 +481,141 @@ struct TagEntry : public EntryBaseDropped { 
    std::string format(const LogStatistics& stat, log_id_t id) const;

};



struct TagNameEntry : public EntryBaseDropped {

    // We do not care that a dropped entry does, or does not exist, because

    // the size will always report zero.  But if it does, we need to account

    // for the ones that transitioned from a known tag to chatty so that we

    // do not spring a leak on the dropped counts.

    static size_t droppedElsewhere;



    pid_t tid;

    pid_t pid;

    uid_t uid;

    std::string* alloc;

    std::experimental::string_view name;  // Saves space if const char*



    explicit TagNameEntry(LogBufferElement* element)

        : EntryBaseDropped(element),

          tid(element->getTid()),

          pid(element->getPid()),

          uid(element->getUid()),

          alloc(nullptr) {

        if (element->isBinary()) {

            uint32_t tag = element->getTag();

            if (tag) {

                const char* cp = android::tagToName(tag);

                if (cp) {

                    name = std::experimental::string_view(cp, strlen(cp));

                    return;

                }

            }

            alloc = new std::string(

                android::base::StringPrintf("[%" PRIu32 "]", tag));

            if (!alloc) return;

            name = std::experimental::string_view(alloc->c_str(), alloc->size());

            return;

        }

        const char* msg = element->getMsg();

        if (!msg) {

            name = std::experimental::string_view("chatty", strlen("chatty"));

            return;

        }

        ++msg;

        unsigned short len = element->getMsgLen();

        len = (len <= 1) ? 0 : strnlen(msg, len - 1);

        if (!len) {

            name = std::experimental::string_view("<NULL>", strlen("<NULL>"));

            return;

        }

        alloc = new std::string(msg, len);

        if (!alloc) return;

        name = std::experimental::string_view(alloc->c_str(), alloc->size());

    }



    explicit TagNameEntry(TagNameEntry&& rval)

        : tid(rval.tid),

          pid(rval.pid),

          uid(rval.uid),

          alloc(rval.alloc),

          name(rval.name.data(), rval.name.length()) {

        rval.alloc = nullptr;

    }



    explicit TagNameEntry(const TagNameEntry& rval)

        : tid(rval.tid),

          pid(rval.pid),

          uid(rval.uid),

          alloc(rval.alloc ? new std::string(*rval.alloc) : nullptr),

          name(alloc ? alloc->data() : rval.name.data(), rval.name.length()) {

    }



    ~TagNameEntry() {

        if (alloc) delete alloc;

    }



    const std::experimental::string_view& getKey() const {

        return name;

    }

    const pid_t& getTid() const {

        return tid;

    }

    const pid_t& getPid() const {

        return pid;

    }

    const uid_t& getUid() const {

        return uid;

    }

    const char* getName() const {

        return name.data();

    }

    size_t getNameAllocLength() const {

        return alloc ? alloc->length() + 1 : 0;

    }



    size_t getDropped() {

        if (__predict_false(name == "chatty")) {  // plug the leak

            dropped += droppedElsewhere;

            droppedElsewhere = 0;

        }

        return EntryBaseDropped::getDropped();

    }



    inline void add(LogBufferElement* element) {

        if (uid != element->getUid()) {

            uid = -1;

        }

        if (pid != element->getPid()) {

            pid = -1;

        }

        if (tid != element->getTid()) {

            tid = -1;

        }

        // Fixup of dropped can be deferred.

        EntryBaseDropped::add(element);

    }



    inline bool subtract(LogBufferElement* element) {

        if (__predict_false(name == "chatty")) {  // plug the leak

            dropped += droppedElsewhere;

            droppedElsewhere = 0;

        }

        return EntryBaseDropped::subtract(element);

    }



    inline void drop(LogBufferElement* element) {

        if (__predict_false(name == "chatty")) {  // plug the leak

            dropped += droppedElsewhere;

            droppedElsewhere = 0;

        } else {

            ++droppedElsewhere;

        }

        return EntryBaseDropped::drop(element);

    }



    std::string formatHeader(const std::string& name, log_id_t id) const;

    std::string format(const LogStatistics& stat, log_id_t id) const;

};



template <typename TEntry>

class LogFindWorst {

    std::unique_ptr<const TEntry* []> sorted;
@@ -550,9 +689,15 @@ class LogStatistics { 
    // security tag list

    tagTable_t securityTagTable;



    // global tag list

    typedef LogHashtable<std::experimental::string_view, TagNameEntry>

        tagNameTable_t;

    tagNameTable_t tagNameTable;



    size_t sizeOf() const {

        size_t size = sizeof(*this) + pidTable.sizeOf() + tidTable.sizeOf() +

                      tagTable.sizeOf() + securityTagTable.sizeOf() +

                      tagNameTable.sizeOf() +

                      (pidTable.size() * sizeof(pidTable_t::iterator)) +

                      (tagTable.size() * sizeof(tagTable_t::iterator));

        for (auto it : pidTable) {
@@ -563,6 +708,7 @@ class LogStatistics { 
            const char* name = it.second.getName();

            if (name) size += strlen(name) + 1;

        }

        for (auto it : tagNameTable) size += it.second.getNameAllocLength();

        log_id_for_each(id) {

            size += uidTable[id].sizeOf();

            size += uidTable[id].size() * sizeof(uidTable_t::iterator);