am 8913dec5: Merge changes Iddd45a67,Ifdc20b09,Ibc68480d

* commit '8913dec51d33f93e8e96fdd12c8112c5cc7dbb78': logd: disable worst uid prune for events buffer Revert: "logd: default off by-UID spam filter" logd: annotate worst-UID pruned entries
2015-04-13 14:21:39 +00:00 · 2015-04-13 14:21:39 +00:00 · 3c5e3a8251
commit 3c5e3a8251
parent 532d0a11c4 8913dec51d
8 changed files with 267 additions and 40 deletions
--- a/logd/Android.mk
+++ b/logd/Android.mk
@ -32,8 +32,9 @@ LOCAL_SHARED_LIBRARIES := \
 #        "s/^\([0-9]*\)[ \t]*$1[ \t].*/-D`echo $1 | tr a-z A-Z`_LOG_TAG=\1/p" \
 #        $(LOCAL_PATH)/$2/event.logtags)
 #  event_flag := $(call event_logtags,auditd)
+#  event_flag += $(call event_logtags,logd)
 # so make sure we do not regret hard-coding it as follows:
-event_flag := -DAUDITD_LOG_TAG=1003
+event_flag := -DAUDITD_LOG_TAG=1003 -DLOGD_LOG_TAG=1004

 LOCAL_CFLAGS := -Werror $(event_flag)

--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@ -279,7 +279,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
        size_t worst_sizes = 0;
        size_t second_worst_sizes = 0;

-        if ((id != LOG_ID_CRASH) && mPrune.worstUidEnabled()) {
+        if (worstUidEnabledForLogid(id) && mPrune.worstUidEnabled()) {
            std::unique_ptr<const UidEntry *[]> sorted = stats.sort(2, id);

            if (sorted.get()) {
@ -297,6 +297,8 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
        }

        bool kick = false;
+        bool leading = true;
+        LogBufferElement *last = NULL;
        for(it = mLogElements.begin(); it != mLogElements.end();) {
            LogBufferElement *e = *it;

@ -309,26 +311,87 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
                continue;
            }

-            uid_t uid = e->getUid();
+            unsigned short dropped = e->getDropped();

-            // !Worst and !BlackListed?
-            if ((uid != worst) && (!hasBlacklist || !mPrune.naughty(e))) {
+            // remove any leading drops
+            if (leading && dropped) {
+                it = erase(it);
+                continue;
+            }
+
+            pid_t pid = e->getPid();
+
+            // merge any drops
+            if (last && dropped
+             && ((dropped + last->getDropped()) < USHRT_MAX)
+             && (last->getPid() == pid)
+             && (last->getTid() == e->getTid())) {
+                it = mLogElements.erase(it);
+                stats.erase(e);
+                delete e;
+                last->setDropped(dropped + last->getDropped());
+                continue;
+            }
+
+            leading = false;
+
+            if (hasBlacklist && mPrune.naughty(e)) {
+                last = NULL;
+                it = erase(it);
+                if (dropped) {
+                    continue;
+                }
+
+                pruneRows--;
+                if (pruneRows == 0) {
+                    break;
+                }
+
+                if (e->getUid() == worst) {
+                    kick = true;
+                    if (worst_sizes < second_worst_sizes) {
+                        break;
+                    }
+                    worst_sizes -= e->getMsgLen();
+                }
+                continue;
+            }
+
+            if (dropped) {
+                last = e;
+                ++it;
+                continue;
+            }
+
+            if (e->getUid() != worst) {
+                last = NULL;
                ++it;
                continue;
            }

-            unsigned short len = e->getMsgLen();
-            it = erase(it);
            pruneRows--;
            if (pruneRows == 0) {
                break;
            }

-            if (uid != worst) {
-                continue;
-            }
-
            kick = true;
+
+            unsigned short len = e->getMsgLen();
+            stats.drop(e);
+            e->setDropped(1);
+            // merge any drops
+            if (last
+             && (last->getDropped() < (USHRT_MAX - 1))
+             && (last->getPid() == pid)
+             && (last->getTid() == e->getTid())) {
+                it = mLogElements.erase(it);
+                stats.erase(e);
+                delete e;
+                last->setDropped(last->getDropped() + 1);
+            } else {
+                last = e;
+                ++it;
+            }
            if (worst_sizes < second_worst_sizes) {
                break;
            }
--- a/logd/LogBufferElement.cpp
+++ b/logd/LogBufferElement.cpp
@ -14,14 +14,17 @@
 * limitations under the License.
 */

+#include <endian.h>
 #include <stdio.h>
 #include <string.h>
 #include <time.h>
 #include <unistd.h>

 #include <log/logger.h>
+#include <private/android_logger.h>

 #include "LogBufferElement.h"
+#include "LogCommand.h"
 #include "LogReader.h"

 const uint64_t LogBufferElement::FLUSH_ERROR(0);
@ -45,11 +48,59 @@ LogBufferElement::~LogBufferElement() {
    delete [] mMsg;
 }

+// assumption: mMsg == NULL
+size_t LogBufferElement::populateDroppedMessage(char *&buffer, bool privileged) {
+    static const char format_uid[] = "uid=%u dropped=%u";
+    static const size_t unprivileged_offset = 7;
+    static const char tag[] = "logd";
+
+    size_t len;
+    if (privileged) {
+        len = snprintf(NULL, 0, format_uid, mUid, mDropped);
+    } else {
+        len = snprintf(NULL, 0, format_uid + unprivileged_offset, mDropped);
+    }
+
+    size_t hdrLen;
+    if (mLogId == LOG_ID_EVENTS) {
+        hdrLen = sizeof(android_log_event_string_t);
+    } else {
+        hdrLen = 1 + sizeof(tag);
+    }
+
+    buffer = static_cast<char *>(calloc(1, hdrLen + len + 1));
+    if (!buffer) {
+        return 0;
+    }
+
+    size_t retval = hdrLen + len;
+    if (mLogId == LOG_ID_EVENTS) {
+        android_log_event_string_t *e = reinterpret_cast<android_log_event_string_t *>(buffer);
+
+        e->header.tag = htole32(LOGD_LOG_TAG);
+        e->type = EVENT_TYPE_STRING;
+        e->length = htole32(len);
+    } else {
+        ++retval;
+        buffer[0] = ANDROID_LOG_INFO;
+        strcpy(buffer + 1, tag);
+    }
+
+    if (privileged) {
+        snprintf(buffer + hdrLen, len + 1, format_uid, mUid, mDropped);
+    } else {
+        snprintf(buffer + hdrLen, len + 1, format_uid + unprivileged_offset, mDropped);
+    }
+
+    return retval;
+}
+
 uint64_t LogBufferElement::flushTo(SocketClient *reader) {
    struct logger_entry_v3 entry;
+
    memset(&entry, 0, sizeof(struct logger_entry_v3));
+
    entry.hdr_size = sizeof(struct logger_entry_v3);
-    entry.len = mMsgLen;
    entry.lid = mLogId;
    entry.pid = mPid;
    entry.tid = mTid;
@ -59,11 +110,26 @@ uint64_t LogBufferElement::flushTo(SocketClient *reader) {
    struct iovec iovec[2];
    iovec[0].iov_base = &entry;
    iovec[0].iov_len = sizeof(struct logger_entry_v3);
-    iovec[1].iov_base = mMsg;
-    iovec[1].iov_len = mMsgLen;
-    if (reader->sendDatav(iovec, 2)) {
-        return FLUSH_ERROR;
+
+    char *buffer = NULL;
+
+    if (!mMsg) {
+        entry.len = populateDroppedMessage(buffer, clientHasLogCredentials(reader));
+        if (!entry.len) {
+            return mSequence;
+        }
+        iovec[1].iov_base = buffer;
+    } else {
+        entry.len = mMsgLen;
+        iovec[1].iov_base = mMsg;
+    }
+    iovec[1].iov_len = entry.len;
+
+    uint64_t retval = reader->sendDatav(iovec, 2) ? FLUSH_ERROR : mSequence;
+
+    if (buffer) {
+        free(buffer);
    }

-    return mSequence;
+    return retval;
 }
--- a/logd/LogBufferElement.h
+++ b/logd/LogBufferElement.h
@ -18,6 +18,7 @@
 #define _LOGD_LOG_BUFFER_ELEMENT_H__

 #include <stdatomic.h>
+#include <stdlib.h>
 #include <sys/types.h>

 #include <sysutils/SocketClient.h>
@ -32,17 +33,27 @@ char *uidToName(uid_t uid);

 }

+static inline bool worstUidEnabledForLogid(log_id_t id) {
+    return (id != LOG_ID_CRASH) && (id != LOG_ID_EVENTS);
+}
+
 class LogBufferElement {
    const log_id_t mLogId;
    const uid_t mUid;
    const pid_t mPid;
    const pid_t mTid;
    char *mMsg;
-    const unsigned short mMsgLen;
+    union {
+        const unsigned short mMsgLen; // mMSg != NULL
+        unsigned short mDropped;      // mMsg == NULL
+    };
    const uint64_t mSequence;
    const log_time mRealTime;
    static atomic_int_fast64_t sequence;

+    // assumption: mMsg == NULL
+    size_t populateDroppedMessage(char *&buffer, bool privileged);
+
 public:
    LogBufferElement(log_id_t log_id, log_time realtime,
                     uid_t uid, pid_t pid, pid_t tid,
@ -53,7 +64,15 @@ public:
    uid_t getUid(void) const { return mUid; }
    pid_t getPid(void) const { return mPid; }
    pid_t getTid(void) const { return mTid; }
-    unsigned short getMsgLen() const { return mMsgLen; }
+    unsigned short getDropped(void) const { return mMsg ? 0 : mDropped; }
+    unsigned short setDropped(unsigned short value) {
+        if (mMsg) {
+            free(mMsg);
+            mMsg = NULL;
+        }
+        return mDropped = value;
+    }
+    unsigned short getMsgLen() const { return mMsg ? mMsgLen : 0; }
    uint64_t getSequence(void) const { return mSequence; }
    static uint64_t getCurrentSequence(void) { return sequence.load(memory_order_relaxed); }
    log_time getRealTime(void) const { return mRealTime; }
--- a/logd/LogStatistics.cpp
+++ b/logd/LogStatistics.cpp
@ -71,16 +71,19 @@ void LogStatistics::add(LogBufferElement *e) {
    ++mElements[log_id];

    uid_t uid = e->getUid();
+    unsigned short dropped = e->getDropped();
    android::hash_t hash = android::hash_type(uid);
    uidTable_t &table = uidTable[log_id];
    ssize_t index = table.find(-1, hash, uid);
    if (index == -1) {
        UidEntry initEntry(uid);
        initEntry.add(size);
+        initEntry.add_dropped(dropped);
        table.add(hash, initEntry);
    } else {
        UidEntry &entry = table.editEntryAt(index);
        entry.add(size);
+        entry.add_dropped(dropped);
    }

    mSizesTotal[log_id] += size;
@ -96,6 +99,7 @@ void LogStatistics::add(LogBufferElement *e) {
    if (index == -1) {
        PidEntry initEntry(pid, uid, android::pidToName(pid));
        initEntry.add(size);
+        initEntry.add_dropped(dropped);
        pidTable.add(hash, initEntry);
    } else {
        PidEntry &entry = pidTable.editEntryAt(index);
@ -109,6 +113,7 @@ void LogStatistics::add(LogBufferElement *e) {
            }
        }
        entry.add(size);
+        entry.add_dropped(dropped);
    }
 }

@ -119,12 +124,13 @@ void LogStatistics::subtract(LogBufferElement *e) {
    --mElements[log_id];

    uid_t uid = e->getUid();
+    unsigned short dropped = e->getDropped();
    android::hash_t hash = android::hash_type(uid);
    uidTable_t &table = uidTable[log_id];
    ssize_t index = table.find(-1, hash, uid);
    if (index != -1) {
        UidEntry &entry = table.editEntryAt(index);
-        if (entry.subtract(size)) {
+        if (entry.subtract(size) || entry.subtract_dropped(dropped)) {
            table.removeAt(index);
        }
    }
@ -138,12 +144,43 @@ void LogStatistics::subtract(LogBufferElement *e) {
    index = pidTable.find(-1, hash, pid);
    if (index != -1) {
        PidEntry &entry = pidTable.editEntryAt(index);
-        if (entry.subtract(size)) {
+        if (entry.subtract(size) || entry.subtract_dropped(dropped)) {
            pidTable.removeAt(index);
        }
    }
 }

+// Atomically set an entry to drop
+// entry->setDropped(1) must follow this call, caller should do this explicitly.
+void LogStatistics::drop(LogBufferElement *e) {
+    log_id_t log_id = e->getLogId();
+    unsigned short size = e->getMsgLen();
+    mSizes[log_id] -= size;
+
+    uid_t uid = e->getUid();
+    android::hash_t hash = android::hash_type(uid);
+    typeof uidTable[0] &table = uidTable[log_id];
+    ssize_t index = table.find(-1, hash, uid);
+    if (index != -1) {
+        UidEntry &entry = table.editEntryAt(index);
+        entry.subtract(size);
+        entry.add_dropped(1);
+    }
+
+    if (!enable) {
+        return;
+    }
+
+    pid_t pid = e->getPid();
+    hash = android::hash_type(pid);
+    index = pidTable.find(-1, hash, pid);
+    if (index != -1) {
+        PidEntry &entry = pidTable.editEntryAt(index);
+        entry.subtract(size);
+        entry.add_dropped(1);
+    }
+}
+
 // caller must own and free character string
 char *LogStatistics::uidToName(uid_t uid) {
    // Local hard coded favourites
@ -191,12 +228,22 @@ char *LogStatistics::uidToName(uid_t uid) {
 }

 static void format_line(android::String8 &output,
-        android::String8 &name, android::String8 &size) {
-    static const size_t total_len = 70;
+        android::String8 &name, android::String8 &size, android::String8 &pruned) {
+    static const size_t pruned_len = 6;
+    static const size_t total_len = 70 + pruned_len;

-    output.appendFormat("%s%*s\n", name.string(),
-        (int)std::max(total_len - name.length() - 1, size.length() + 1),
-        size.string());
+    ssize_t drop_len = std::max(pruned.length() + 1, pruned_len);
+    ssize_t size_len = std::max(size.length() + 1,
+                                total_len - name.length() - drop_len - 1);
+
+    if (pruned.length()) {
+        output.appendFormat("%s%*s%*s\n", name.string(),
+                                          (int)size_len, size.string(),
+                                          (int)drop_len, pruned.string());
+    } else {
+        output.appendFormat("%s%*s\n", name.string(),
+                                       (int)size_len, size.string());
+    }
 }

 void LogStatistics::format(char **buf, uid_t uid, unsigned int logMask) {
@ -285,14 +332,18 @@ void LogStatistics::format(char **buf, uid_t uid, unsigned int logMask) {
                    output.appendFormat(
                        "\n\nChattiest UIDs in %s:\n",
                        android_log_id_to_name(id));
-                    android::String8 name("UID");
-                    android::String8 size("Size");
-                    format_line(output, name, size);
                } else {
                    output.appendFormat(
                        "\n\nLogging for your UID in %s:\n",
                        android_log_id_to_name(id));
                }
+                android::String8 name("UID");
+                android::String8 size("Size");
+                android::String8 pruned("Pruned");
+                if (!worstUidEnabledForLogid(id)) {
+                    pruned.setTo("");
+                }
+                format_line(output, name, size, pruned);
                headerPrinted = true;
            }

@ -307,7 +358,13 @@ void LogStatistics::format(char **buf, uid_t uid, unsigned int logMask) {
            android::String8 size("");
            size.appendFormat("%zu", entry->getSizes());

-            format_line(output, name, size);
+            android::String8 pruned("");
+            size_t dropped = entry->getDropped();
+            if (dropped) {
+                pruned.appendFormat("%zu", dropped);
+            }
+
+            format_line(output, name, size, pruned);
        }
    }

@ -330,7 +387,8 @@ void LogStatistics::format(char **buf, uid_t uid, unsigned int logMask) {
                }
                android::String8 name("  PID/UID");
                android::String8 size("Size");
-                format_line(output, name, size);
+                android::String8 pruned("Pruned");
+                format_line(output, name, size, pruned);
                headerPrinted = true;
            }

@ -350,7 +408,13 @@ void LogStatistics::format(char **buf, uid_t uid, unsigned int logMask) {
            android::String8 size("");
            size.appendFormat("%zu", entry->getSizes());

-            format_line(output, name, size);
+            android::String8 pruned("");
+            size_t dropped = entry->getDropped();
+            if (dropped) {
+                pruned.appendFormat("%zu", dropped);
+            }
+
+            format_line(output, name, size, pruned);
        }
    }

--- a/logd/LogStatistics.h
+++ b/logd/LogStatistics.h
@ -78,13 +78,18 @@ public:
 struct UidEntry {
    const uid_t uid;
    size_t size;
+    size_t dropped;

-    UidEntry(uid_t uid):uid(uid),size(0) { }
+    UidEntry(uid_t uid):uid(uid),size(0),dropped(0) { }

    inline const uid_t&getKey() const { return uid; }
    size_t getSizes() const { return size; }
+    size_t getDropped() const { return dropped; }
+
    inline void add(size_t s) { size += s; }
-    inline bool subtract(size_t s) { size -= s; return !size; }
+    inline void add_dropped(size_t d) { dropped += d; }
+    inline bool subtract(size_t s) { size -= s; return !dropped && !size; }
+    inline bool subtract_dropped(size_t d) { dropped -= d; return !dropped && !size; }
 };

 struct PidEntry {
@ -92,13 +97,15 @@ struct PidEntry {
    uid_t uid;
    char *name;
    size_t size;
+    size_t dropped;

-    PidEntry(pid_t p, uid_t u, char *n):pid(p),uid(u),name(n),size(0) { }
+    PidEntry(pid_t p, uid_t u, char *n):pid(p),uid(u),name(n),size(0),dropped(0) { }
    PidEntry(const PidEntry &c):
        pid(c.pid),
        uid(c.uid),
        name(c.name ? strdup(c.name) : NULL),
-        size(c.size) { }
+        size(c.size),
+        dropped(c.dropped) { }
    ~PidEntry() { free(name); }

    const pid_t&getKey() const { return pid; }
@ -107,8 +114,11 @@ struct PidEntry {
    const char*getName() const { return name; }
    char *setName(char *n) { free(name); return name = n; }
    size_t getSizes() const { return size; }
+    size_t getDropped() const { return dropped; }
    inline void add(size_t s) { size += s; }
-    inline bool subtract(size_t s) { size -= s; return !size; }
+    inline void add_dropped(size_t d) { dropped += d; }
+    inline bool subtract(size_t s) { size -= s; return !dropped && !size; }
+    inline bool subtract_dropped(size_t d) { dropped -= d; return !dropped && !size; }
 };

 // Log Statistics
@ -134,6 +144,10 @@ public:

    void add(LogBufferElement *entry);
    void subtract(LogBufferElement *entry);
+    // entry->setDropped(1) must follow this call
+    void drop(LogBufferElement *entry);
+    // Correct for merging two entries referencing dropped content
+    void erase(LogBufferElement *e) { --mElements[e->getLogId()]; }

    std::unique_ptr<const UidEntry *[]> sort(size_t n, log_id i) { return uidTable[i].sort(n); }

--- a/logd/LogWhiteBlackList.cpp
+++ b/logd/LogWhiteBlackList.cpp
@ -15,7 +15,6 @@
 */

 #include <ctype.h>
-#include <malloc.h>

 #include <utils/String8.h>

@ -53,7 +52,7 @@ void Prune::format(char **strp) {
 }

 PruneList::PruneList()
-        : mWorstUidEnabled(false) {
+        : mWorstUidEnabled(true) {
    mNaughty.clear();
    mNice.clear();
 }
@ -71,7 +70,7 @@ PruneList::~PruneList() {
 }

 int PruneList::init(char *str) {
-    mWorstUidEnabled = false;
+    mWorstUidEnabled = true;
    PruneCollection::iterator it;
    for (it = mNice.begin(); it != mNice.end();) {
        delete (*it);
--- a/logd/event.logtags
+++ b/logd/event.logtags
@ -34,3 +34,4 @@
 # TODO: generate ".java" and ".h" files with integer constants from this file.

 1003  auditd (avc|3)
+1004  logd (dropped|3)