Merge changes I12d6aa4e,I9e802113,I2b30e0fc,Iaf387b9e
* changes: logcat: remove dead label code logcat: do not stop on unexpected log ID Revert "logd: Add minimum time bucket statistics" liblog: Instrument logging of logd write drops
This commit is contained in:
Mark Salyzyn
Gerrit Code Review
commit
051222c243
|
|
@ -16,6 +16,8 @@
|
|||
LOCAL_PATH := $(my-dir)
|
||||
include $(CLEAR_VARS)
|
||||
|
||||
liblog_cflags := $(shell sed -n 's/^\([0-9]*\)[ \t]*liblog[ \t].*/-DLIBLOG_LOG_TAG=\1/p' $(LOCAL_PATH)/event.logtags)
|
||||
|
||||
ifneq ($(TARGET_USES_LOGD),false)
|
||||
liblog_sources := logd_write.c
|
||||
else
|
||||
|
|
@ -45,7 +47,7 @@ else
|
|||
uio.c
|
||||
endif
|
||||
|
||||
liblog_host_sources := $(liblog_sources) fake_log_device.c
|
||||
liblog_host_sources := $(liblog_sources) fake_log_device.c event.logtags
|
||||
liblog_target_sources := $(liblog_sources) log_time.cpp log_is_loggable.c
|
||||
ifneq ($(TARGET_USES_LOGD),false)
|
||||
liblog_target_sources += log_read.c
|
||||
|
|
@ -57,7 +59,7 @@ endif
|
|||
# ========================================================
|
||||
LOCAL_MODULE := liblog
|
||||
LOCAL_SRC_FILES := $(liblog_host_sources)
|
||||
LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 -Werror
|
||||
LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 -Werror $(liblog_cflags)
|
||||
LOCAL_MULTILIB := both
|
||||
include $(BUILD_HOST_STATIC_LIBRARY)
|
||||
|
||||
|
|
@ -76,13 +78,13 @@ include $(BUILD_HOST_SHARED_LIBRARY)
|
|||
include $(CLEAR_VARS)
|
||||
LOCAL_MODULE := liblog
|
||||
LOCAL_SRC_FILES := $(liblog_target_sources)
|
||||
LOCAL_CFLAGS := -Werror
|
||||
LOCAL_CFLAGS := -Werror $(liblog_cflags)
|
||||
include $(BUILD_STATIC_LIBRARY)
|
||||
|
||||
include $(CLEAR_VARS)
|
||||
LOCAL_MODULE := liblog
|
||||
LOCAL_WHOLE_STATIC_LIBRARIES := liblog
|
||||
LOCAL_CFLAGS := -Werror
|
||||
LOCAL_CFLAGS := -Werror $(liblog_cflags)
|
||||
include $(BUILD_SHARED_LIBRARY)
|
||||
|
||||
include $(call first-makefiles-under,$(LOCAL_PATH))
|
||||
|
|
|
|||
|
|
@ -131,6 +131,33 @@ DESCRIPTION
|
|||
when opening the sub-log. It is recommended to open the log
|
||||
ANDROID_LOG_RDONLY in these cases.
|
||||
|
||||
ERRORS
|
||||
If messages fail, a negative error code will be returned to the caller.
|
||||
|
||||
The -ENOTCONN return code indicates that the logger daemon is stopped.
|
||||
|
||||
The -EBADF return code indicates that the log access point can not be
|
||||
opened, or the log buffer id is out of range.
|
||||
|
||||
For the -EAGAIN return code, this means that the logging message was
|
||||
temporarily backed-up either because of Denial Of Service (DOS) logging
|
||||
pressure from some chatty application or service in the Android system,
|
||||
or if too small of a value is set in /proc/sys/net/unix/max_dgram_qlen.
|
||||
To aid in diagnosing the occurence of this, a binary event from liblog
|
||||
will be sent to the log daemon once a new message can get through
|
||||
indicating how many messages were dropped as a result. Please take
|
||||
action to resolve the structural problems at the source.
|
||||
|
||||
It is generally not advised for the caller to retry the -EAGAIN return
|
||||
code as this will only make the problem(s) worse and cause your
|
||||
application to temporarily drop to the logger daemon priority, BATCH
|
||||
scheduling policy and background task cgroup. If you require a group of
|
||||
messages to be passed atomically, merge them into one message with
|
||||
embedded newlines to the maximum length LOGGER_ENTRY_MAX_PAYLOAD.
|
||||
|
||||
Other return codes from writing operation can be returned. Since the
|
||||
library retries on EINTR, -EINTR should never be returned.
|
||||
|
||||
SEE ALSO
|
||||
syslogd(8)
|
||||
|
||||
|
|
|
|||
|
|
@ -0,0 +1,36 @@
|
|||
# The entries in this file map a sparse set of log tag numbers to tag names.
|
||||
# This is installed on the device, in /system/etc, and parsed by logcat.
|
||||
#
|
||||
# Tag numbers are decimal integers, from 0 to 2^31. (Let's leave the
|
||||
# negative values alone for now.)
|
||||
#
|
||||
# Tag names are one or more ASCII letters and numbers or underscores, i.e.
|
||||
# "[A-Z][a-z][0-9]_". Do not include spaces or punctuation (the former
|
||||
# impacts log readability, the latter makes regex searches more annoying).
|
||||
#
|
||||
# Tag numbers and names are separated by whitespace. Blank lines and lines
|
||||
# starting with '#' are ignored.
|
||||
#
|
||||
# Optionally, after the tag names can be put a description for the value(s)
|
||||
# of the tag. Description are in the format
|
||||
# (<name>|data type[|data unit])
|
||||
# Multiple values are separated by commas.
|
||||
#
|
||||
# The data type is a number from the following values:
|
||||
# 1: int
|
||||
# 2: long
|
||||
# 3: string
|
||||
# 4: list
|
||||
#
|
||||
# The data unit is a number taken from the following list:
|
||||
# 1: Number of objects
|
||||
# 2: Number of bytes
|
||||
# 3: Number of milliseconds
|
||||
# 4: Number of allocations
|
||||
# 5: Id
|
||||
# 6: Percent
|
||||
# Default value for data of type int/long is 2 (bytes).
|
||||
#
|
||||
# TODO: generate ".java" and ".h" files with integer constants from this file.
|
||||
|
||||
1005 liblog (dropped|1)
|
||||
|
|
@ -13,12 +13,14 @@
|
|||
* See the License for the specific language governing permissions and
|
||||
* limitations under the License.
|
||||
*/
|
||||
#include <endian.h>
|
||||
#include <errno.h>
|
||||
#include <fcntl.h>
|
||||
#if !defined(_WIN32)
|
||||
#include <pthread.h>
|
||||
#endif
|
||||
#include <stdarg.h>
|
||||
#include <stdatomic.h>
|
||||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
#include <string.h>
|
||||
|
|
@ -172,6 +174,7 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
|
|||
size_t i, payload_size;
|
||||
static uid_t last_uid = AID_ROOT; /* logd *always* starts up as AID_ROOT */
|
||||
static pid_t last_pid = (pid_t) -1;
|
||||
static atomic_int_fast32_t dropped;
|
||||
|
||||
if (last_uid == AID_ROOT) { /* have we called to get the UID yet? */
|
||||
last_uid = getuid();
|
||||
|
|
@ -206,7 +209,6 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
|
|||
pmsg_header.uid = last_uid;
|
||||
pmsg_header.pid = last_pid;
|
||||
|
||||
header.id = log_id;
|
||||
header.tid = gettid();
|
||||
header.realtime.tv_sec = ts.tv_sec;
|
||||
header.realtime.tv_nsec = ts.tv_nsec;
|
||||
|
|
@ -216,6 +218,28 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
|
|||
newVec[1].iov_base = (unsigned char *) &header;
|
||||
newVec[1].iov_len = sizeof(header);
|
||||
|
||||
if (logd_fd > 0) {
|
||||
int32_t snapshot = atomic_exchange_explicit(&dropped, 0, memory_order_relaxed);
|
||||
if (snapshot) {
|
||||
android_log_event_int_t buffer;
|
||||
|
||||
header.id = LOG_ID_EVENTS;
|
||||
buffer.header.tag = htole32(LIBLOG_LOG_TAG);
|
||||
buffer.payload.type = EVENT_TYPE_INT;
|
||||
buffer.payload.data = htole32(snapshot);
|
||||
|
||||
newVec[2].iov_base = &buffer;
|
||||
newVec[2].iov_len = sizeof(buffer);
|
||||
|
||||
ret = TEMP_FAILURE_RETRY(writev(logd_fd, newVec + 1, 2));
|
||||
if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) {
|
||||
atomic_fetch_add_explicit(&dropped, snapshot, memory_order_relaxed);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
header.id = log_id;
|
||||
|
||||
for (payload_size = 0, i = header_length; i < nr + header_length; i++) {
|
||||
newVec[i].iov_base = vec[i - header_length].iov_base;
|
||||
payload_size += newVec[i].iov_len = vec[i - header_length].iov_len;
|
||||
|
|
@ -281,6 +305,8 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
|
|||
|
||||
if (ret > (ssize_t)sizeof(header)) {
|
||||
ret -= sizeof(header);
|
||||
} else if (ret == -EAGAIN) {
|
||||
atomic_fetch_add_explicit(&dropped, 1, memory_order_relaxed);
|
||||
}
|
||||
#endif
|
||||
|
||||
|
|
|
|||
|
|
@ -38,14 +38,12 @@ struct log_device_t {
|
|||
struct logger *logger;
|
||||
struct logger_list *logger_list;
|
||||
bool printed;
|
||||
char label;
|
||||
|
||||
log_device_t* next;
|
||||
|
||||
log_device_t(const char* d, bool b, char l) {
|
||||
log_device_t(const char* d, bool b) {
|
||||
device = d;
|
||||
binary = b;
|
||||
label = l;
|
||||
next = NULL;
|
||||
printed = false;
|
||||
}
|
||||
|
|
@ -61,9 +59,7 @@ static int g_maxRotatedLogs = DEFAULT_MAX_ROTATED_LOGS; // 0 means "unbounded"
|
|||
static int g_outFD = -1;
|
||||
static off_t g_outByteCount = 0;
|
||||
static int g_printBinary = 0;
|
||||
static int g_devCount = 0;
|
||||
|
||||
static EventTagMap* g_eventTagMap = NULL;
|
||||
static int g_devCount = 0; // >1 means multiple
|
||||
|
||||
static int openLogFile (const char *pathname)
|
||||
{
|
||||
|
|
@ -133,8 +129,15 @@ static void processBuffer(log_device_t* dev, struct log_msg *buf)
|
|||
char binaryMsgBuf[1024];
|
||||
|
||||
if (dev->binary) {
|
||||
static bool hasOpenedEventTagMap = false;
|
||||
static EventTagMap *eventTagMap = NULL;
|
||||
|
||||
if (!eventTagMap && !hasOpenedEventTagMap) {
|
||||
eventTagMap = android_openEventTagMap(EVENT_TAG_MAP_FILE);
|
||||
hasOpenedEventTagMap = true;
|
||||
}
|
||||
err = android_log_processBinaryLogBuffer(&buf->entry_v1, &entry,
|
||||
g_eventTagMap,
|
||||
eventTagMap,
|
||||
binaryMsgBuf,
|
||||
sizeof(binaryMsgBuf));
|
||||
//printf(">>> pri=%d len=%d msg='%s'\n",
|
||||
|
|
@ -147,16 +150,6 @@ static void processBuffer(log_device_t* dev, struct log_msg *buf)
|
|||
}
|
||||
|
||||
if (android_log_shouldPrintLine(g_logformat, entry.tag, entry.priority)) {
|
||||
if (false && g_devCount > 1) {
|
||||
binaryMsgBuf[0] = dev->label;
|
||||
binaryMsgBuf[1] = ' ';
|
||||
bytesWritten = write(g_outFD, binaryMsgBuf, 2);
|
||||
if (bytesWritten < 0) {
|
||||
perror("output error");
|
||||
exit(-1);
|
||||
}
|
||||
}
|
||||
|
||||
bytesWritten = android_log_printLogLine(g_logformat, g_outFD, &entry);
|
||||
|
||||
if (bytesWritten < 0) {
|
||||
|
|
@ -331,7 +324,6 @@ int main(int argc, char **argv)
|
|||
const char *forceFilters = NULL;
|
||||
log_device_t* devices = NULL;
|
||||
log_device_t* dev;
|
||||
bool needBinary = false;
|
||||
bool printDividers = false;
|
||||
struct logger_list *logger_list;
|
||||
unsigned int tail_lines = 0;
|
||||
|
|
@ -469,7 +461,6 @@ int main(int argc, char **argv)
|
|||
|
||||
devices = dev = NULL;
|
||||
android::g_devCount = 0;
|
||||
needBinary = false;
|
||||
for(int i = LOG_ID_MIN; i < LOG_ID_MAX; ++i) {
|
||||
const char *name = android_log_id_to_name((log_id_t)i);
|
||||
log_id_t log_id = android_name_to_log_id(name);
|
||||
|
|
@ -479,7 +470,7 @@ int main(int argc, char **argv)
|
|||
}
|
||||
|
||||
bool binary = strcmp(name, "events") == 0;
|
||||
log_device_t* d = new log_device_t(name, binary, *name);
|
||||
log_device_t* d = new log_device_t(name, binary);
|
||||
|
||||
if (dev) {
|
||||
dev->next = d;
|
||||
|
|
@ -488,26 +479,20 @@ int main(int argc, char **argv)
|
|||
devices = dev = d;
|
||||
}
|
||||
android::g_devCount++;
|
||||
if (binary) {
|
||||
needBinary = true;
|
||||
}
|
||||
}
|
||||
break;
|
||||
}
|
||||
|
||||
bool binary = strcmp(optarg, "events") == 0;
|
||||
if (binary) {
|
||||
needBinary = true;
|
||||
}
|
||||
|
||||
if (devices) {
|
||||
dev = devices;
|
||||
while (dev->next) {
|
||||
dev = dev->next;
|
||||
}
|
||||
dev->next = new log_device_t(optarg, binary, optarg[0]);
|
||||
dev->next = new log_device_t(optarg, binary);
|
||||
} else {
|
||||
devices = new log_device_t(optarg, binary, optarg[0]);
|
||||
devices = new log_device_t(optarg, binary);
|
||||
}
|
||||
android::g_devCount++;
|
||||
}
|
||||
|
|
@ -641,14 +626,14 @@ int main(int argc, char **argv)
|
|||
}
|
||||
|
||||
if (!devices) {
|
||||
dev = devices = new log_device_t("main", false, 'm');
|
||||
dev = devices = new log_device_t("main", false);
|
||||
android::g_devCount = 1;
|
||||
if (android_name_to_log_id("system") == LOG_ID_SYSTEM) {
|
||||
dev = dev->next = new log_device_t("system", false, 's');
|
||||
dev = dev->next = new log_device_t("system", false);
|
||||
android::g_devCount++;
|
||||
}
|
||||
if (android_name_to_log_id("crash") == LOG_ID_CRASH) {
|
||||
dev = dev->next = new log_device_t("crash", false, 'c');
|
||||
dev = dev->next = new log_device_t("crash", false);
|
||||
android::g_devCount++;
|
||||
}
|
||||
}
|
||||
|
|
@ -848,17 +833,15 @@ int main(int argc, char **argv)
|
|||
//LOG_EVENT_LONG(11, 0x1122334455667788LL);
|
||||
//LOG_EVENT_STRING(0, "whassup, doc?");
|
||||
|
||||
if (needBinary)
|
||||
android::g_eventTagMap = android_openEventTagMap(EVENT_TAG_MAP_FILE);
|
||||
|
||||
dev = NULL;
|
||||
log_device_t unexpected("unexpected", false);
|
||||
while (1) {
|
||||
struct log_msg log_msg;
|
||||
log_device_t* d;
|
||||
int ret = android_logger_list_read(logger_list, &log_msg);
|
||||
|
||||
if (ret == 0) {
|
||||
fprintf(stderr, "read: Unexpected EOF!\n");
|
||||
fprintf(stderr, "read: unexpected EOF!\n");
|
||||
exit(EXIT_FAILURE);
|
||||
}
|
||||
|
||||
|
|
@ -868,7 +851,7 @@ int main(int argc, char **argv)
|
|||
}
|
||||
|
||||
if (ret == -EIO) {
|
||||
fprintf(stderr, "read: Unexpected EOF!\n");
|
||||
fprintf(stderr, "read: unexpected EOF!\n");
|
||||
exit(EXIT_FAILURE);
|
||||
}
|
||||
if (ret == -EINVAL) {
|
||||
|
|
@ -885,8 +868,9 @@ int main(int argc, char **argv)
|
|||
}
|
||||
}
|
||||
if (!d) {
|
||||
fprintf(stderr, "read: Unexpected log ID!\n");
|
||||
exit(EXIT_FAILURE);
|
||||
android::g_devCount = 2; // set to Multiple
|
||||
d = &unexpected;
|
||||
d->binary = log_msg.id() == LOG_ID_EVENTS;
|
||||
}
|
||||
|
||||
if (dev != d) {
|
||||
|
|
|
|||
|
|
@ -93,8 +93,7 @@ static unsigned long property_get_size(const char *key) {
|
|||
}
|
||||
|
||||
LogBuffer::LogBuffer(LastLogTimes *times)
|
||||
: dgramQlenStatistics(false)
|
||||
, mTimes(*times) {
|
||||
: mTimes(*times) {
|
||||
pthread_mutex_init(&mLogElementsLock, NULL);
|
||||
|
||||
static const char global_tuneable[] = "persist.logd.size"; // Settings App
|
||||
|
|
@ -150,23 +149,6 @@ void LogBuffer::log(log_id_t log_id, log_time realtime,
|
|||
while (last != mLogElements.begin()) {
|
||||
--it;
|
||||
if ((*it)->getRealTime() <= realtime) {
|
||||
// halves the peak performance, use with caution
|
||||
if (dgramQlenStatistics) {
|
||||
LogBufferElementCollection::iterator ib = it;
|
||||
unsigned short buckets, num = 1;
|
||||
for (unsigned short i = 0; (buckets = stats.dgramQlen(i)); ++i) {
|
||||
buckets -= num;
|
||||
num += buckets;
|
||||
while (buckets && (--ib != mLogElements.begin())) {
|
||||
--buckets;
|
||||
}
|
||||
if (buckets) {
|
||||
break;
|
||||
}
|
||||
stats.recordDiff(
|
||||
elem->getRealTime() - (*ib)->getRealTime(), i);
|
||||
}
|
||||
}
|
||||
break;
|
||||
}
|
||||
last = it;
|
||||
|
|
|
|||
|
|
@ -37,7 +37,6 @@ class LogBuffer {
|
|||
pthread_mutex_t mLogElementsLock;
|
||||
|
||||
LogStatistics stats;
|
||||
bool dgramQlenStatistics;
|
||||
|
||||
PruneList mPrune;
|
||||
|
||||
|
|
@ -63,11 +62,6 @@ public:
|
|||
// *strp uses malloc, use free to release.
|
||||
void formatStatistics(char **strp, uid_t uid, unsigned int logMask);
|
||||
|
||||
void enableDgramQlenStatistics() {
|
||||
stats.enableDgramQlenStatistics();
|
||||
dgramQlenStatistics = true;
|
||||
}
|
||||
|
||||
void enableStatistics() {
|
||||
stats.enableStatistics();
|
||||
}
|
||||
|
|
|
|||
|
|
@ -395,71 +395,11 @@ size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) {
|
|||
|
||||
LogStatistics::LogStatistics()
|
||||
: mStatistics(false)
|
||||
, dgramQlenStatistics(false)
|
||||
, start(CLOCK_MONOTONIC) {
|
||||
log_id_for_each(i) {
|
||||
mSizes[i] = 0;
|
||||
mElements[i] = 0;
|
||||
}
|
||||
|
||||
for(unsigned short bucket = 0; dgramQlen(bucket); ++bucket) {
|
||||
mMinimum[bucket].tv_sec = mMinimum[bucket].tv_sec_max;
|
||||
mMinimum[bucket].tv_nsec = mMinimum[bucket].tv_nsec_max;
|
||||
}
|
||||
}
|
||||
|
||||
// Each bucket below represents a dgramQlen of log messages. By
|
||||
// finding the minimum period of time from start to finish
|
||||
// of each dgramQlen, we can get a performance expectation for
|
||||
// the user space logger. The net result is that the period
|
||||
// of time divided by the dgramQlen will give us the average time
|
||||
// between log messages; at the point where the average time
|
||||
// is greater than the throughput capability of the logger
|
||||
// we will not longer require the benefits of the FIFO formed
|
||||
// by max_dgram_qlen. We will also expect to see a very visible
|
||||
// knee in the average time between log messages at this point,
|
||||
// so we do not necessarily have to compare the rate against the
|
||||
// measured performance (BM_log_maximum_retry) of the logger.
|
||||
//
|
||||
// for example (reformatted):
|
||||
//
|
||||
// Minimum time between log events per dgramQlen:
|
||||
// 1 2 3 5 10 20 30 50 100 200 300 400 500 600
|
||||
// 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5
|
||||
//
|
||||
// demonstrates a clear knee rising at 100, so this means that for this
|
||||
// case max_dgram_qlen = 100 would be more than sufficient to handle the
|
||||
// worst that the system could stuff into the logger. The
|
||||
// BM_log_maximum_retry performance (derated by the log collection) on the
|
||||
// same system was 33.2us so we would almost be fine with max_dgram_qlen = 50.
|
||||
// BM_log_maxumum_retry with statistics off is roughly 20us, so
|
||||
// max_dgram_qlen = 20 would work. We will be more than willing to have
|
||||
// a large engineering margin so the rule of thumb that lead us to 100 is
|
||||
// fine.
|
||||
//
|
||||
// bucket dgramQlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300
|
||||
const unsigned short LogStatistics::mBuckets[] = {
|
||||
1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600
|
||||
};
|
||||
|
||||
unsigned short LogStatistics::dgramQlen(unsigned short bucket) {
|
||||
if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) {
|
||||
return 0;
|
||||
}
|
||||
return mBuckets[bucket];
|
||||
}
|
||||
|
||||
unsigned long long LogStatistics::minimum(unsigned short bucket) {
|
||||
if (mMinimum[bucket].tv_sec == mMinimum[bucket].tv_sec_max) {
|
||||
return 0;
|
||||
}
|
||||
return mMinimum[bucket].nsec();
|
||||
}
|
||||
|
||||
void LogStatistics::recordDiff(log_time diff, unsigned short bucket) {
|
||||
if ((diff.tv_sec || diff.tv_nsec) && (mMinimum[bucket] > diff)) {
|
||||
mMinimum[bucket] = diff;
|
||||
}
|
||||
}
|
||||
|
||||
void LogStatistics::add(unsigned short size,
|
||||
|
|
@ -709,55 +649,6 @@ void LogStatistics::format(char **buf,
|
|||
pids.clear();
|
||||
}
|
||||
|
||||
if (dgramQlenStatistics) {
|
||||
const unsigned short spaces_time = 6;
|
||||
const unsigned long long max_seconds = 100000;
|
||||
spaces = 0;
|
||||
string.append("\n\nMinimum time between log events per max_dgram_qlen:\n");
|
||||
for(unsigned short i = 0; dgramQlen(i); ++i) {
|
||||
oldLength = string.length();
|
||||
if (spaces < 0) {
|
||||
spaces = 0;
|
||||
}
|
||||
string.appendFormat("%*s%u", spaces, "", dgramQlen(i));
|
||||
spaces += spaces_time + oldLength - string.length();
|
||||
}
|
||||
string.append("\n");
|
||||
spaces = 0;
|
||||
unsigned short n;
|
||||
for(unsigned short i = 0; (n = dgramQlen(i)); ++i) {
|
||||
unsigned long long duration = minimum(i);
|
||||
if (duration) {
|
||||
duration /= n;
|
||||
if (duration >= (NS_PER_SEC * max_seconds)) {
|
||||
duration = NS_PER_SEC * (max_seconds - 1);
|
||||
}
|
||||
oldLength = string.length();
|
||||
if (spaces < 0) {
|
||||
spaces = 0;
|
||||
}
|
||||
string.appendFormat("%*s", spaces, "");
|
||||
if (duration >= (NS_PER_SEC * 10)) {
|
||||
string.appendFormat("%llu",
|
||||
(duration + (NS_PER_SEC / 2))
|
||||
/ NS_PER_SEC);
|
||||
} else if (duration >= (NS_PER_SEC / (1000 / 10))) {
|
||||
string.appendFormat("%llum",
|
||||
(duration + (NS_PER_SEC / 2 / 1000))
|
||||
/ (NS_PER_SEC / 1000));
|
||||
} else if (duration >= (NS_PER_SEC / (1000000 / 10))) {
|
||||
string.appendFormat("%lluu",
|
||||
(duration + (NS_PER_SEC / 2 / 1000000))
|
||||
/ (NS_PER_SEC / 1000000));
|
||||
} else {
|
||||
string.appendFormat("%llun", duration);
|
||||
}
|
||||
spaces -= string.length() - oldLength;
|
||||
}
|
||||
spaces += spaces_time;
|
||||
}
|
||||
}
|
||||
|
||||
log_id_for_each(i) {
|
||||
if (!(logMask & (1 << i))) {
|
||||
continue;
|
||||
|
|
|
|||
|
|
@ -145,7 +145,6 @@ class LogStatistics {
|
|||
size_t mElements[LOG_ID_MAX];
|
||||
|
||||
bool mStatistics;
|
||||
bool dgramQlenStatistics;
|
||||
|
||||
static const unsigned short mBuckets[14];
|
||||
log_time mMinimum[sizeof(mBuckets) / sizeof(mBuckets[0])];
|
||||
|
|
@ -157,11 +156,7 @@ public:
|
|||
|
||||
LidStatistics &id(log_id_t log_id) { return LogIds[log_id]; }
|
||||
|
||||
void enableDgramQlenStatistics() { dgramQlenStatistics = true; }
|
||||
void enableStatistics() { mStatistics = true; }
|
||||
static unsigned short dgramQlen(unsigned short bucket);
|
||||
unsigned long long minimum(unsigned short bucket);
|
||||
void recordDiff(log_time diff, unsigned short bucket);
|
||||
|
||||
void add(unsigned short size, log_id_t log_id, uid_t uid, pid_t pid);
|
||||
void subtract(unsigned short size, log_id_t log_id, uid_t uid, pid_t pid);
|
||||
|
|
|
|||
|
|
@ -7,12 +7,6 @@ logd.auditd.dmesg bool true selinux audit messages duplicated and
|
|||
logd.statistics bool depends Enable logcat -S statistics.
|
||||
ro.config.low_ram bool false if true, logd.statistics default false
|
||||
ro.build.type string if user, logd.statistics default false
|
||||
logd.statistics.dgram_qlen bool false Record dgram_qlen statistics. This
|
||||
represents a performance impact and
|
||||
is used to determine the platform's
|
||||
minimum domain socket network FIFO
|
||||
size (see source for details) based
|
||||
on typical load (logcat -S to view)
|
||||
persist.logd.size number 256K default size of the buffer for all
|
||||
log ids at initial startup, at runtime
|
||||
use: logcat -b all -G <value>
|
||||
|
|
|
|||
|
|
@ -155,9 +155,6 @@ int main() {
|
|||
|
||||
LogBuffer *logBuf = new LogBuffer(times);
|
||||
|
||||
if (property_get_bool("logd.statistics.dgram_qlen", false)) {
|
||||
logBuf->enableDgramQlenStatistics();
|
||||
}
|
||||
{
|
||||
char property[PROPERTY_VALUE_MAX];
|
||||
property_get("ro.build.type", property, "");
|
||||
|
|
|
|||
|
|
@ -192,164 +192,6 @@ TEST(logd, statistics) {
|
|||
EXPECT_TRUE(NULL != events_logs);
|
||||
#endif
|
||||
|
||||
// Parse timing stats
|
||||
|
||||
cp = strstr(cp, "Minimum time between log events per dgram_qlen:");
|
||||
|
||||
if (cp) {
|
||||
while (*cp && (*cp != '\n')) {
|
||||
++cp;
|
||||
}
|
||||
if (*cp == '\n') {
|
||||
++cp;
|
||||
}
|
||||
|
||||
char *list_of_spans = cp;
|
||||
EXPECT_NE('\0', *list_of_spans);
|
||||
|
||||
unsigned short number_of_buckets = 0;
|
||||
unsigned short *dgram_qlen = NULL;
|
||||
unsigned short bucket = 0;
|
||||
while (*cp && (*cp != '\n')) {
|
||||
bucket = 0;
|
||||
while (isdigit(*cp)) {
|
||||
bucket = bucket * 10 + *cp - '0';
|
||||
++cp;
|
||||
}
|
||||
while (*cp == ' ') {
|
||||
++cp;
|
||||
}
|
||||
if (!bucket) {
|
||||
break;
|
||||
}
|
||||
unsigned short *new_dgram_qlen = new unsigned short[number_of_buckets + 1];
|
||||
EXPECT_TRUE(new_dgram_qlen != NULL);
|
||||
if (dgram_qlen) {
|
||||
memcpy(new_dgram_qlen, dgram_qlen, sizeof(*dgram_qlen) * number_of_buckets);
|
||||
delete [] dgram_qlen;
|
||||
}
|
||||
|
||||
dgram_qlen = new_dgram_qlen;
|
||||
dgram_qlen[number_of_buckets++] = bucket;
|
||||
}
|
||||
|
||||
char *end_of_spans = cp;
|
||||
EXPECT_NE('\0', *end_of_spans);
|
||||
|
||||
EXPECT_LT(5, number_of_buckets);
|
||||
|
||||
unsigned long long *times = new unsigned long long [number_of_buckets];
|
||||
ASSERT_TRUE(times != NULL);
|
||||
|
||||
memset(times, 0, sizeof(*times) * number_of_buckets);
|
||||
|
||||
while (*cp == '\n') {
|
||||
++cp;
|
||||
}
|
||||
|
||||
unsigned short number_of_values = 0;
|
||||
unsigned long long value;
|
||||
while (*cp && (*cp != '\n')) {
|
||||
EXPECT_GE(number_of_buckets, number_of_values);
|
||||
|
||||
value = 0;
|
||||
while (isdigit(*cp)) {
|
||||
value = value * 10ULL + *cp - '0';
|
||||
++cp;
|
||||
}
|
||||
|
||||
switch(*cp) {
|
||||
case ' ':
|
||||
case '\n':
|
||||
value *= 1000ULL;
|
||||
/* FALLTHRU */
|
||||
case 'm':
|
||||
value *= 1000ULL;
|
||||
/* FALLTHRU */
|
||||
case 'u':
|
||||
value *= 1000ULL;
|
||||
/* FALLTHRU */
|
||||
case 'n':
|
||||
default:
|
||||
break;
|
||||
}
|
||||
while (*++cp == ' ');
|
||||
|
||||
if (!value) {
|
||||
break;
|
||||
}
|
||||
|
||||
times[number_of_values] = value;
|
||||
++number_of_values;
|
||||
}
|
||||
|
||||
#ifdef TARGET_USES_LOGD
|
||||
EXPECT_EQ(number_of_values, number_of_buckets);
|
||||
#endif
|
||||
|
||||
FILE *fp;
|
||||
ASSERT_TRUE(NULL != (fp = fopen("/proc/sys/net/unix/max_dgram_qlen", "r")));
|
||||
|
||||
unsigned max_dgram_qlen = 0;
|
||||
fscanf(fp, "%u", &max_dgram_qlen);
|
||||
|
||||
fclose(fp);
|
||||
|
||||
// Find launch point
|
||||
unsigned short launch = 0;
|
||||
unsigned long long total = 0;
|
||||
do {
|
||||
total += times[launch];
|
||||
} while (((++launch < number_of_buckets)
|
||||
&& ((total / launch) >= (times[launch] / 8ULL)))
|
||||
|| (launch == 1)); // too soon
|
||||
|
||||
bool failure = number_of_buckets <= launch;
|
||||
if (!failure) {
|
||||
unsigned short l = launch;
|
||||
if (l >= number_of_buckets) {
|
||||
l = number_of_buckets - 1;
|
||||
}
|
||||
failure = max_dgram_qlen < dgram_qlen[l];
|
||||
}
|
||||
|
||||
// We can get failure if at any time liblog_benchmarks has been run
|
||||
// because designed to overload /proc/sys/net/unix/max_dgram_qlen even
|
||||
// at excessive values like 20000. It does so to measure the raw processing
|
||||
// performance of logd.
|
||||
if (failure) {
|
||||
cp = find_benchmark_spam(cp);
|
||||
}
|
||||
|
||||
if (cp) {
|
||||
// Fake a failure, but without the failure code
|
||||
if (number_of_buckets <= launch) {
|
||||
printf ("Expected: number_of_buckets > launch, actual: %u vs %u\n",
|
||||
number_of_buckets, launch);
|
||||
}
|
||||
if (launch >= number_of_buckets) {
|
||||
launch = number_of_buckets - 1;
|
||||
}
|
||||
if (max_dgram_qlen < dgram_qlen[launch]) {
|
||||
printf ("Expected: max_dgram_qlen >= dgram_qlen[%d],"
|
||||
" actual: %u vs %u\n",
|
||||
launch, max_dgram_qlen, dgram_qlen[launch]);
|
||||
}
|
||||
} else
|
||||
#ifndef TARGET_USES_LOGD
|
||||
if (total)
|
||||
#endif
|
||||
{
|
||||
EXPECT_GT(number_of_buckets, launch);
|
||||
if (launch >= number_of_buckets) {
|
||||
launch = number_of_buckets - 1;
|
||||
}
|
||||
EXPECT_GE(max_dgram_qlen, dgram_qlen[launch]);
|
||||
}
|
||||
|
||||
delete [] dgram_qlen;
|
||||
delete [] times;
|
||||
}
|
||||
delete [] buf;
|
||||
}
|
||||
|
||||
|
|
|
|||
Loading…
Reference in New Issue