Skip to content

Commit

Permalink
logd: optimize code hotspots
Browse files Browse the repository at this point in the history 
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
  • Loading branch information
Mark Salyzyn authored and Steve Kondik committed Nov 1, 2015
1 parent c5a324f commit 75e8077
Show file tree
Hide file tree
Showing 8 changed files with 72 additions and 50 deletions.
35 changes: 20 additions & 15 deletions logd/LogAudit.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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>

Expand Down Expand Up @@ -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);
Expand All @@ -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
Expand Down Expand Up @@ -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);
Expand Down
27 changes: 15 additions & 12 deletions logd/LogBufferElement.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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) {
Expand All @@ -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) {
Expand Down
2 changes: 1 addition & 1 deletion logd/LogBufferElement.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,7 @@ class LogBufferElement {
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;
Expand Down
31 changes: 14 additions & 17 deletions logd/LogKlog.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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 = "";
}
Expand All @@ -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;
}
}
Expand All @@ -727,19 +727,17 @@ 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 ...
rc = -EINVAL;
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
Expand All @@ -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) {
Expand Down
2 changes: 1 addition & 1 deletion logd/LogReader.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand Down
4 changes: 2 additions & 2 deletions logd/LogStatistics.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
}
Expand Down Expand Up @@ -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;
Expand Down
4 changes: 2 additions & 2 deletions logd/LogStatistics.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;
}
Expand Down
17 changes: 17 additions & 0 deletions logd/LogUtils.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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__

0 comments on commit 75e8077

Please sign in to comment.