logd: optimize code hotspots

Discovered that we had a few libc hotspots. Adjust code to generally
reduce or nullify the number of calls to malloc, free, strlen,
strcmp, strncmp, memcmp & strncasecmp. Total gain looks to be about
3% of logd's processing time. malloc still contributes to 3%, but all
others are now total 0.5%.

Bug: 23685592
Change-Id: Ife721121667969260cdb8b055524ae90f5911278

8 files changed, 72 insertions, 50 deletions

diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp
index 7db17d1..808d17a 100644
--- a/logd/LogAudit.cpp
+++ b/logd/LogAudit.cpp
@@ -24,6 +24,7 @@
 #include <sys/uio.h>
 #include <syslog.h>
 
+#include <log/logger.h>
 #include <private/android_filesystem_config.h>
 #include <private/android_logger.h>
 
@@ -153,15 +154,16 @@ int LogAudit::logPrint(const char *fmt, ...) {
 
     // log to events
 
-    size_t l = strlen(str);
+    size_t l = strnlen(str, LOGGER_ENTRY_MAX_PAYLOAD);
     size_t n = l + sizeof(android_log_event_string_t);
 
     bool notify = false;
 
-    android_log_event_string_t *event = static_cast<android_log_event_string_t *>(malloc(n));
-    if (!event) {
-        rc = -ENOMEM;
-    } else {
+    {   // begin scope for event buffer
+        uint32_t buffer[(n + sizeof(uint32_t) - 1) / sizeof(uint32_t)];
+
+        android_log_event_string_t *event
+            = reinterpret_cast<android_log_event_string_t *>(buffer);
         event->header.tag = htole32(AUDITD_LOG_TAG);
         event->type = EVENT_TYPE_STRING;
         event->length = htole32(l);
@@ -170,11 +172,10 @@ int LogAudit::logPrint(const char *fmt, ...) {
         rc = logbuf->log(LOG_ID_EVENTS, now, uid, pid, tid,
                          reinterpret_cast<char *>(event),
                          (n <= USHRT_MAX) ? (unsigned short) n : USHRT_MAX);
-        free(event);
-
         if (rc >= 0) {
             notify = true;
         }
+        // end scope for event buffer
     }
 
     // log to main
@@ -206,24 +207,28 @@ int LogAudit::logPrint(const char *fmt, ...) {
         l = strlen(comm) + 1;
         ecomm = "";
     }
-    n = (estr - str) + strlen(ecomm) + l + 2;
+    size_t b = estr - str;
+    if (b > LOGGER_ENTRY_MAX_PAYLOAD) {
+        b = LOGGER_ENTRY_MAX_PAYLOAD;
+    }
+    size_t e = strnlen(ecomm, LOGGER_ENTRY_MAX_PAYLOAD - b);
+    n = b + e + l + 2;
+
+    {   // begin scope for main buffer
+        char newstr[n];
 
-    char *newstr = static_cast<char *>(malloc(n));
-    if (!newstr) {
-        rc = -ENOMEM;
-    } else {
         *newstr = info ? ANDROID_LOG_INFO : ANDROID_LOG_WARN;
         strlcpy(newstr + 1, comm, l);
-        strncpy(newstr + 1 + l, str, estr - str);
-        strcpy(newstr + 1 + l + (estr - str), ecomm);
+        strncpy(newstr + 1 + l, str, b);
+        strncpy(newstr + 1 + l + b, ecomm, e);
 
         rc = logbuf->log(LOG_ID_MAIN, now, uid, pid, tid, newstr,
                          (n <= USHRT_MAX) ? (unsigned short) n : USHRT_MAX);
-        free(newstr);
 
         if (rc >= 0) {
             notify = true;
         }
+        // end scope for main buffer
     }
 
     free(commfree);
diff --git a/logd/LogBufferElement.cpp b/logd/LogBufferElement.cpp
index 9fb1439..150ce22 100644
--- a/logd/LogBufferElement.cpp
+++ b/logd/LogBufferElement.cpp
@@ -91,7 +91,8 @@ char *android::tidToName(pid_t tid) {
         size_t retval_len = strlen(retval);
         size_t name_len = strlen(name);
         // KISS: ToDo: Only checks prefix truncated, not suffix, or both
-        if ((retval_len < name_len) && !strcmp(retval, name + name_len - retval_len)) {
+        if ((retval_len < name_len)
+                && !fast<strcmp>(retval, name + name_len - retval_len)) {
             free(retval);
             retval = name;
         } else {
@@ -123,14 +124,16 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer,
         commName = parent->pidToName(mPid);
         parent->unlock();
     }
-    size_t len = name ? strlen(name) : 0;
-    if (len && commName && !strncmp(name, commName, len)) {
-        if (commName[len] == '\0') {
-            free(commName);
-            commName = NULL;
-        } else {
-            free(name);
-            name = NULL;
+    if (name && name[0] && commName && (name[0] == commName[0])) {
+        size_t len = strlen(name + 1);
+        if (!strncmp(name + 1, commName + 1, len)) {
+            if (commName[len + 1] == '\0') {
+                free(commName);
+                commName = NULL;
+            } else {
+                free(name);
+                name = NULL;
+            }
         }
     }
     if (name) {
@@ -150,9 +153,9 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer,
         }
     }
     // identical to below to calculate the buffer size required
-    len = snprintf(NULL, 0, format_uid, mUid, name ? name : "",
-                   commName ? commName : "",
-                   mDropped, (mDropped > 1) ? "s" : "");
+    size_t len = snprintf(NULL, 0, format_uid, mUid, name ? name : "",
+                          commName ? commName : "",
+                          mDropped, (mDropped > 1) ? "s" : "");
 
     size_t hdrLen;
     if (mLogId == LOG_ID_EVENTS) {
diff --git a/logd/LogBufferElement.h b/logd/LogBufferElement.h
index 4877939..30e43c6 100644
--- a/logd/LogBufferElement.h
+++ b/logd/LogBufferElement.h
@@ -64,7 +64,7 @@ public:
     unsigned short getDropped(void) const { return mMsg ? 0 : mDropped; }
     unsigned short setDropped(unsigned short value) {
         if (mMsg) {
-            free(mMsg);
+            delete [] mMsg;
             mMsg = NULL;
         }
         return mDropped = value;
diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp
index 242d7a0..d28161e 100644
--- a/logd/LogKlog.cpp
+++ b/logd/LogKlog.cpp
@@ -306,7 +306,7 @@ static const char *strnstr(const char *s, size_t len, const char *needle) {
                 }
                 --len;
             } while (*s++ != c);
-        } while (memcmp(s, needle, needleLen) != 0);
+        } while (fast<memcmp>(s, needle, needleLen));
         s--;
     }
     return s;
@@ -588,7 +588,7 @@ int LogKlog::log(const char *buf, size_t len) {
         const char *bt, *et, *cp;
 
         bt = p;
-        if (!strncmp(p, "[INFO]", 6)) {
+        if (!fast<strncmp>(p, "[INFO]", 6)) {
             // <PRI>[<TIME>] "[INFO]"<tag> ":" message
             bt = p + 6;
             taglen -= 6;
@@ -612,10 +612,10 @@ int LogKlog::log(const char *buf, size_t len) {
             p = cp + 1;
         } else if (taglen) {
             size = et - bt;
-            if (strncmp(bt, cp, size)) {
+            if ((*bt == *cp) && fast<strncmp>(bt + 1, cp + 1, size - 1)) {
                 // <PRI>[<TIME>] <tag>_host '<tag>.<num>' : message
-                if (!strncmp(bt + size - 5, "_host", 5)
-                        && !strncmp(bt, cp, size - 5)) {
+                if (!fast<strncmp>(bt + size - 5, "_host", 5)
+                        && !fast<strncmp>(bt + 1, cp + 1, size - 6)) {
                     const char *b = cp;
                     cp += size - 5;
                     taglen -= size - 5;
@@ -694,10 +694,10 @@ int LogKlog::log(const char *buf, size_t len) {
             // register names like x18 but not driver names like en0
                 || ((size == 3) && (isdigit(tag[1]) && isdigit(tag[2])))
             // blacklist
-                || ((size == 3) && !strncmp(tag, "CPU", 3))
-                || ((size == 7) && !strncasecmp(tag, "WARNING", 7))
-                || ((size == 5) && !strncasecmp(tag, "ERROR", 5))
-                || ((size == 4) && !strncasecmp(tag, "INFO", 4))) {
+                || ((size == 3) && !fast<strncmp>(tag, "CPU", 3))
+                || ((size == 7) && !fast<strncasecmp>(tag, "WARNING", 7))
+                || ((size == 5) && !fast<strncasecmp>(tag, "ERROR", 5))
+                || ((size == 4) && !fast<strncasecmp>(tag, "INFO", 4))) {
             p = start;
             etag = tag = "";
         }
@@ -709,7 +709,7 @@ int LogKlog::log(const char *buf, size_t len) {
     const char *mp = strnrchr(tag, ']', taglen);
     if (mp && (++mp < etag)) {
         size_t s = etag - mp;
-        if (((s + s) < taglen) && !memcmp(mp, mp - 1 - s, s)) {
+        if (((s + s) < taglen) && !fast<memcmp>(mp, mp - 1 - s, s)) {
             taglen = mp - tag;
         }
     }
@@ -727,6 +727,9 @@ int LogKlog::log(const char *buf, size_t len) {
         p = " ";
         b = 1;
     }
+    if (b > LOGGER_ENTRY_MAX_PAYLOAD) {
+        b = LOGGER_ENTRY_MAX_PAYLOAD;
+    }
     size_t n = 1 + taglen + 1 + b + 1;
     int rc = n;
     if ((taglen > n) || (b > n)) { // Can not happen ...
@@ -734,12 +737,7 @@ int LogKlog::log(const char *buf, size_t len) {
         return rc;
     }
 
-    // Allocate a buffer to hold the interpreted log message
-    char *newstr = reinterpret_cast<char *>(malloc(n));
-    if (!newstr) {
-        rc = -ENOMEM;
-        return rc;
-    }
+    char newstr[n];
     char *np = newstr;
 
     // Convert priority into single-byte Android logger priority
@@ -759,7 +757,6 @@ int LogKlog::log(const char *buf, size_t len) {
     // Log message
     rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr,
                      (n <= USHRT_MAX) ? (unsigned short) n : USHRT_MAX);
-    free(newstr);
 
     // notify readers
     if (!rc) {
diff --git a/logd/LogReader.cpp b/logd/LogReader.cpp
index c7deec0..3833843 100644
--- a/logd/LogReader.cpp
+++ b/logd/LogReader.cpp
@@ -95,7 +95,7 @@ bool LogReader::onDataAvailable(SocketClient *cli) {
     }
 
     bool nonBlock = false;
-    if (strncmp(buffer, "dumpAndClose", 12) == 0) {
+    if (!fast<strncmp>(buffer, "dumpAndClose", 12)) {
         // Allow writer to get some cycles, and wait for pending notifications
         sched_yield();
         LogTimeEntry::lock();
diff --git a/logd/LogStatistics.cpp b/logd/LogStatistics.cpp
index 48c2fe6..099a4c4 100644
--- a/logd/LogStatistics.cpp
+++ b/logd/LogStatistics.cpp
@@ -51,7 +51,7 @@ char *pidToName(pid_t pid) {
             if (ret > 0) {
                 buffer[sizeof(buffer)-1] = '\0';
                 // frameworks intermediate state
-                if (strcmp(buffer, "<pre-initialized>")) {
+                if (fast<strcmp>(buffer, "<pre-initialized>")) {
                     retval = strdup(buffer);
                 }
             }
@@ -170,7 +170,7 @@ char *LogStatistics::uidToName(uid_t uid) {
             if (n) {
                 if (!name) {
                     name = strdup(n);
-                } else if (strcmp(name, n)) {
+                } else if (fast<strcmp>(name, n)) {
                     free(name);
                     name = NULL;
                     break;
diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h
index 05466f6..42084de 100644
--- a/logd/LogStatistics.h
+++ b/logd/LogStatistics.h
@@ -189,7 +189,7 @@ struct PidEntry : public EntryBaseDropped {
     const char*getName() const { return name; }
 
     inline void add(pid_t p) {
-        if (name && !strncmp(name, "zygote", 6)) {
+        if (name && !fast<strncmp>(name, "zygote", 6)) {
             free(name);
             name = NULL;
         }
@@ -241,7 +241,7 @@ struct TidEntry : public EntryBaseDropped {
     const char*getName() const { return name; }
 
     inline void add(pid_t t) {
-        if (name && !strncmp(name, "zygote", 6)) {
+        if (name && !fast<strncmp>(name, "zygote", 6)) {
             free(name);
             name = NULL;
         }
diff --git a/logd/LogUtils.h b/logd/LogUtils.h
index 117bc59..533eb1c 100644
--- a/logd/LogUtils.h
+++ b/logd/LogUtils.h
@@ -42,4 +42,21 @@ static inline bool worstUidEnabledForLogid(log_id_t id) {
     return (id != LOG_ID_CRASH) && (id != LOG_ID_KERNEL) && (id != LOG_ID_EVENTS);
 }
 
+template <int (*cmp)(const char *l, const char *r, const size_t s)>
+static inline int fast(const char *l, const char *r, const size_t s) {
+    return (*l != *r) || cmp(l + 1, r + 1, s - 1);
+}
+
+template <int (*cmp)(const void *l, const void *r, const size_t s)>
+static inline int fast(const void *lv, const void *rv, const size_t s) {
+    const char *l = static_cast<const char *>(lv);
+    const char *r = static_cast<const char *>(rv);
+    return (*l != *r) || cmp(l + 1, r + 1, s - 1);
+}
+
+template <int (*cmp)(const char *l, const char *r)>
+static inline int fast(const char *l, const char *r) {
+    return (*l != *r) || cmp(l + 1, r + 1);
+}
+
 #endif // _LOGD_LOG_UTILS_H__