android_system_core/logd/LogBufferElement.cpp
Mark Salyzyn 807e40ecc9 liblog: logd: Add android_lookupEventTag_len()
Allows us to mitigate the impact of MAP_PRIVATE and copy on write by
calling android_lookupEventTag_len instead of android_lookupEventTag,
and delaying the copy on write impact to the later.  We return a
string length in a supplied location along with the string pointer
with android_lookupEventTag_len(const EventTagMap* map, size_t* len,
int tag).  The string is not guaranteed to be nul terminated.  Since
android_lookupEventTag() called even once can cause the memory
impact, we will mark it as deprecated, but we currently have no
timeframe for removal since this is a very old interface.

Add an API for __android_log_is_loggable_len() that accepts the non
null terminated content and fixup callers that would gain because the
length is known prior to the call either in the compiler or at
runtime.  Tackle transition to android_lookupEventTag_len() and
fixup callers.

On any application that performs logging (eg: com.android.phone)

/proc/<pid>/smaps before:

xxxxxxxxxx-xxxxxxxxxx rw-p 00000000 fd:00 463 /system/etc/event-log-tags
Size:                 20 kB
Rss:                  20 kB
Pss:                   1 kB
Shared_Clean:          0 kB
Shared_Dirty:         20 kB
Private_Clean:         0 kB
Private_Dirty:         0 kB
Referenced:            0 kB
Anonymous:            20 kB
AnonHugePages:         0 kB
Swap:                  0 kB
SwapPss:               0 kB
KernelPageSize:        4 kB
MMUPageSize:           4 kB
Locked:                0 kB
VmFlags: rd wr mr mw me ac

/proc/<pid>/smaps after:

xxxxxxxxxx-xxxxxxxxxx rw-p 00000000 fd:00 1773 /system/etc/event-log-tags
Size:                 20 kB
Rss:                  20 kB
Pss:                   1 kB
Shared_Clean:         20 kB  (was 0kB)
Shared_Dirty:          0 kB  (was 20kB)
Private_Clean:         0 kB
Private_Dirty:         0 kB
Referenced:           20 kB  (was 0kB)
Anonymous:             0 kB  (was 20kB)
AnonHugePages:         0 kB
Swap:                  0 kB
SwapPss:               0 kB
KernelPageSize:        4 kB
MMUPageSize:           4 kB
Locked:                0 kB
VmFlags: rd wr mr mw me ac

Added liblog-unit-tests --gtest_filter=liblog.event_log_tags to
check for Shared_Clean: to not be 0 and Anonymous: to be 0 for
all processes referencing event-log-tags.  Which can include multiple
references to /system/etc/event-log-tags and future possible refs to
/data/misc/logd/event-log-tags and /dev/event-log-tags.  We want
failure messages to help point to errant code using the deprecated
interface.

This change saves 1/4MB of memory or more on a typical system.

Test: gTest liblog-unit-tests
Bug: 31456426
Change-Id: I9e08e44d9092bd96fe704b5709242e7195281d33
2016-10-03 11:08:34 -07:00

245 lines
7.1 KiB
C++

/*
* Copyright (C) 2012-2014 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include <ctype.h>
#include <endian.h>
#include <fcntl.h>
#include <stdio.h>
#include <string.h>
#include <time.h>
#include <unistd.h>
#include <log/logger.h>
#include <private/android_logger.h>
#include "LogBuffer.h"
#include "LogBufferElement.h"
#include "LogCommand.h"
#include "LogReader.h"
#include "LogUtils.h"
const uint64_t LogBufferElement::FLUSH_ERROR(0);
atomic_int_fast64_t LogBufferElement::sequence(1);
LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime,
uid_t uid, pid_t pid, pid_t tid,
const char *msg, unsigned short len) :
mLogId(log_id),
mUid(uid),
mPid(pid),
mTid(tid),
mMsgLen(len),
mSequence(sequence.fetch_add(1, memory_order_relaxed)),
mRealTime(realtime) {
mMsg = new char[len];
memcpy(mMsg, msg, len);
}
LogBufferElement::~LogBufferElement() {
delete [] mMsg;
}
uint32_t LogBufferElement::getTag() const {
if (((mLogId != LOG_ID_EVENTS) && (mLogId != LOG_ID_SECURITY)) ||
!mMsg || (mMsgLen < sizeof(uint32_t))) {
return 0;
}
return le32toh(reinterpret_cast<android_event_header_t *>(mMsg)->tag);
}
// caller must own and free character string
char *android::tidToName(pid_t tid) {
char *retval = NULL;
char buffer[256];
snprintf(buffer, sizeof(buffer), "/proc/%u/comm", tid);
int fd = open(buffer, O_RDONLY);
if (fd >= 0) {
ssize_t ret = read(fd, buffer, sizeof(buffer));
if (ret >= (ssize_t)sizeof(buffer)) {
ret = sizeof(buffer) - 1;
}
while ((ret > 0) && isspace(buffer[ret - 1])) {
--ret;
}
if (ret > 0) {
buffer[ret] = '\0';
retval = strdup(buffer);
}
close(fd);
}
// if nothing for comm, check out cmdline
char *name = android::pidToName(tid);
if (!retval) {
retval = name;
name = NULL;
}
// check if comm is truncated, see if cmdline has full representation
if (name) {
// impossible for retval to be NULL if name not NULL
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)
&& !fast<strcmp>(retval, name + name_len - retval_len)) {
free(retval);
retval = name;
} else {
free(name);
}
}
return retval;
}
// assumption: mMsg == NULL
size_t LogBufferElement::populateDroppedMessage(char *&buffer,
LogBuffer *parent) {
static const char tag[] = "chatty";
if (!__android_log_is_loggable_len(ANDROID_LOG_INFO,
tag, strlen(tag),
ANDROID_LOG_VERBOSE)) {
return 0;
}
static const char format_uid[] = "uid=%u%s%s expire %u line%s";
parent->lock();
const char *name = parent->uidToName(mUid);
parent->unlock();
const char *commName = android::tidToName(mTid);
if (!commName && (mTid != mPid)) {
commName = android::tidToName(mPid);
}
if (!commName) {
parent->lock();
commName = parent->pidToName(mPid);
parent->unlock();
}
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(const_cast<char *>(commName));
commName = NULL;
} else {
free(const_cast<char *>(name));
name = NULL;
}
}
}
if (name) {
char *buf = NULL;
asprintf(&buf, "(%s)", name);
if (buf) {
free(const_cast<char *>(name));
name = buf;
}
}
if (commName) {
char *buf = NULL;
asprintf(&buf, " %s", commName);
if (buf) {
free(const_cast<char *>(commName));
commName = buf;
}
}
// identical to below to calculate the buffer size required
size_t len = snprintf(NULL, 0, format_uid, mUid, name ? name : "",
commName ? commName : "",
mDropped, (mDropped > 1) ? "s" : "");
size_t hdrLen;
// LOG_ID_SECURITY not strictly needed since spam filter not activated,
// but required for accuracy.
if ((mLogId == LOG_ID_EVENTS) || (mLogId == LOG_ID_SECURITY)) {
hdrLen = sizeof(android_log_event_string_t);
} else {
hdrLen = 1 + sizeof(tag);
}
buffer = static_cast<char *>(calloc(1, hdrLen + len + 1));
if (!buffer) {
free(const_cast<char *>(name));
free(const_cast<char *>(commName));
return 0;
}
size_t retval = hdrLen + len;
if ((mLogId == LOG_ID_EVENTS) || (mLogId == LOG_ID_SECURITY)) {
android_log_event_string_t *event =
reinterpret_cast<android_log_event_string_t *>(buffer);
event->header.tag = htole32(CHATTY_LOG_TAG);
event->type = EVENT_TYPE_STRING;
event->length = htole32(len);
} else {
++retval;
buffer[0] = ANDROID_LOG_INFO;
strcpy(buffer + 1, tag);
}
snprintf(buffer + hdrLen, len + 1, format_uid, mUid, name ? name : "",
commName ? commName : "",
mDropped, (mDropped > 1) ? "s" : "");
free(const_cast<char *>(name));
free(const_cast<char *>(commName));
return retval;
}
uint64_t LogBufferElement::flushTo(SocketClient *reader, LogBuffer *parent,
bool privileged) {
struct logger_entry_v4 entry;
memset(&entry, 0, sizeof(struct logger_entry_v4));
entry.hdr_size = privileged ?
sizeof(struct logger_entry_v4) :
sizeof(struct logger_entry_v3);
entry.lid = mLogId;
entry.pid = mPid;
entry.tid = mTid;
entry.uid = mUid;
entry.sec = mRealTime.tv_sec;
entry.nsec = mRealTime.tv_nsec;
struct iovec iovec[2];
iovec[0].iov_base = &entry;
iovec[0].iov_len = entry.hdr_size;
char *buffer = NULL;
if (!mMsg) {
entry.len = populateDroppedMessage(buffer, parent);
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 retval;
}