diff --git a/liblog/Android.bp b/liblog/Android.bp index 747fcc8dc..310dbf4c3 100644 --- a/liblog/Android.bp +++ b/liblog/Android.bp @@ -15,13 +15,17 @@ // liblog_sources = [ + "config_read.c", + "config_write.c", + "local_logger.c", "log_event_list.c", "log_event_write.c", - "logger_write.c", - "config_write.c", - "logger_name.c", - "logger_lock.c", "log_ratelimit.cpp", + "logger_lock.c", + "logger_name.c", + "logger_read.c", + "logger_write.c", + "logprint.c", ] liblog_host_sources = [ "fake_log_device.c", @@ -29,15 +33,12 @@ liblog_host_sources = [ ] liblog_target_sources = [ "event_tag_map.cpp", - "config_read.c", "log_time.cpp", "properties.c", - "logprint.c", "pmsg_reader.c", "pmsg_writer.c", "logd_reader.c", "logd_writer.c", - "logger_read.c", ] // Shared and static library for host and device diff --git a/liblog/README b/liblog/README index 610338c2f..40a39ad8b 100644 --- a/liblog/README +++ b/liblog/README @@ -108,6 +108,11 @@ SYNOPSIS int android_log_destroy(android_log_context *ctx) + #include + + int android_set_log_frontend(int frontend_flag) + int android_get_log_frontend() + Link with -llog DESCRIPTION @@ -162,6 +167,13 @@ DESCRIPTION when opening the sub-log. It is recommended to open the log ANDROID_LOG_RDONLY in these cases. + android_set_log_frontend() selects frontend filters. Argument is either + LOGGER_DEFAULT, LOGGER_LOGD, LOGGER_NULL or LOGGER_LOCAL. Log to logger + daemon for default or logd, drop contents on floor, or log into local + memory respectively. Both android_set_log_frontend() and + android_get_log_frontend() return the current frontend mask, or a + negative errno for any problems. + ERRORS If messages fail, a negative error code will be returned to the caller. @@ -194,4 +206,4 @@ SEE ALSO - 17 Oct 2016 LIBLOG(3) + 08 Feb 2017 LIBLOG(3) diff --git a/liblog/config_read.c b/liblog/config_read.c index 1f54152b0..b9a281b30 100644 --- a/liblog/config_read.c +++ b/liblog/config_read.c @@ -14,6 +14,8 @@ * limitations under the License. */ +#include + #include "config_read.h" #include "logger.h" @@ -52,11 +54,35 @@ static void __android_log_add_transport( } LIBLOG_HIDDEN void __android_log_config_read() { -#if (FAKE_LOG_DEVICE == 0) - extern struct android_log_transport_read logdLoggerRead; - extern struct android_log_transport_read pmsgLoggerRead; + if (__android_log_frontend & LOGGER_LOCAL) { + extern struct android_log_transport_read localLoggerRead; - __android_log_add_transport(&__android_log_transport_read, &logdLoggerRead); - __android_log_add_transport(&__android_log_persist_read, &pmsgLoggerRead); + __android_log_add_transport(&__android_log_transport_read, + &localLoggerRead); + } + +#if (FAKE_LOG_DEVICE == 0) + if ((__android_log_frontend == LOGGER_DEFAULT) || + (__android_log_frontend & LOGGER_LOGD)) { + extern struct android_log_transport_read logdLoggerRead; + extern struct android_log_transport_read pmsgLoggerRead; + + __android_log_add_transport(&__android_log_transport_read, + &logdLoggerRead); + __android_log_add_transport(&__android_log_persist_read, + &pmsgLoggerRead); + } #endif } + +LIBLOG_HIDDEN void __android_log_config_read_close() { + struct android_log_transport_read *transport; + struct listnode *n; + + read_transport_for_each_safe(transport, n, &__android_log_transport_read) { + list_remove(&transport->node); + } + read_transport_for_each_safe(transport, n, &__android_log_persist_read) { + list_remove(&transport->node); + } +} diff --git a/liblog/config_read.h b/liblog/config_read.h index 49a3b7526..892e80dca 100644 --- a/liblog/config_read.h +++ b/liblog/config_read.h @@ -28,22 +28,31 @@ extern LIBLOG_HIDDEN struct listnode __android_log_persist_read; #define read_transport_for_each(transp, transports) \ for ((transp) = node_to_item((transports)->next, \ - struct android_log_transport_read, node); \ - ((transp) != node_to_item(transports, \ - struct android_log_transport_read, node)); \ + struct android_log_transport_read, node); \ + ((transp) != node_to_item((transports), \ + struct android_log_transport_read, \ + node)) && \ + ((transp) != node_to_item((transp)->node.next, \ + struct android_log_transport_read, \ + node)); \ (transp) = node_to_item((transp)->node.next, \ - struct android_log_transport_read, node)) \ + struct android_log_transport_read, node)) #define read_transport_for_each_safe(transp, n, transports) \ for ((transp) = node_to_item((transports)->next, \ - struct android_log_transport_read, node), \ + struct android_log_transport_read, node), \ (n) = (transp)->node.next; \ - ((transp) != node_to_item(transports, \ - struct android_log_transport_read, node)); \ - (transp) = node_to_item(n, struct android_log_transport_read, node), \ + ((transp) != node_to_item((transports), \ + struct android_log_transport_read, \ + node)) && \ + ((transp) != node_to_item((n), struct android_log_transport_read, \ + node)); \ + (transp) = node_to_item((n), struct android_log_transport_read, \ + node), \ (n) = (transp)->node.next) LIBLOG_HIDDEN void __android_log_config_read(); +LIBLOG_HIDDEN void __android_log_config_read_close(); __END_DECLS diff --git a/liblog/config_write.c b/liblog/config_write.c index d689f631b..583dcff3a 100644 --- a/liblog/config_write.c +++ b/liblog/config_write.c @@ -14,6 +14,8 @@ * limitations under the License. */ +#include + #include "config_write.h" #include "logger.h" @@ -52,15 +54,42 @@ static void __android_log_add_transport( } LIBLOG_HIDDEN void __android_log_config_write() { + if (__android_log_frontend & LOGGER_LOCAL) { + extern struct android_log_transport_write localLoggerWrite; + + __android_log_add_transport(&__android_log_transport_write, + &localLoggerWrite); + } + + if ((__android_log_frontend == LOGGER_DEFAULT) || + (__android_log_frontend & LOGGER_LOGD)) { #if (FAKE_LOG_DEVICE == 0) - extern struct android_log_transport_write logdLoggerWrite; - extern struct android_log_transport_write pmsgLoggerWrite; + extern struct android_log_transport_write logdLoggerWrite; + extern struct android_log_transport_write pmsgLoggerWrite; - __android_log_add_transport(&__android_log_transport_write, &logdLoggerWrite); - __android_log_add_transport(&__android_log_persist_write, &pmsgLoggerWrite); + __android_log_add_transport(&__android_log_transport_write, + &logdLoggerWrite); + __android_log_add_transport(&__android_log_persist_write, + &pmsgLoggerWrite); #else - extern struct android_log_transport_write fakeLoggerWrite; + extern struct android_log_transport_write fakeLoggerWrite; - __android_log_add_transport(&__android_log_transport_write, &fakeLoggerWrite); + __android_log_add_transport(&__android_log_transport_write, + &fakeLoggerWrite); #endif + } +} + +LIBLOG_HIDDEN void __android_log_config_write_close() { + struct android_log_transport_write *transport; + struct listnode *n; + + write_transport_for_each_safe(transport, n, &__android_log_transport_write) { + transport->logMask = 0; + list_remove(&transport->node); + } + write_transport_for_each_safe(transport, n, &__android_log_persist_write) { + transport->logMask = 0; + list_remove(&transport->node); + } } diff --git a/liblog/config_write.h b/liblog/config_write.h index 3b01a9a80..882541130 100644 --- a/liblog/config_write.h +++ b/liblog/config_write.h @@ -29,21 +29,30 @@ extern LIBLOG_HIDDEN struct listnode __android_log_persist_write; #define write_transport_for_each(transp, transports) \ for ((transp) = node_to_item((transports)->next, \ struct android_log_transport_write, node); \ - ((transp) != node_to_item(transports, \ - struct android_log_transport_write, node)); \ + ((transp) != node_to_item((transports), \ + struct android_log_transport_write, \ + node)) && \ + ((transp) != node_to_item((transp)->node.next, \ + struct android_log_transport_write, \ + node)); \ (transp) = node_to_item((transp)->node.next, \ - struct android_log_transport_write, node)) \ + struct android_log_transport_write, node)) #define write_transport_for_each_safe(transp, n, transports) \ for ((transp) = node_to_item((transports)->next, \ struct android_log_transport_write, node), \ (n) = (transp)->node.next; \ - ((transp) != node_to_item(transports, \ - struct android_log_transport_write, node)); \ - (transp) = node_to_item(n, struct android_log_transport_write, node), \ + ((transp) != node_to_item((transports), \ + struct android_log_transport_write, \ + node)) && \ + ((transp) != node_to_item((n), struct android_log_transport_write, \ + node)); \ + (transp) = node_to_item((n), struct android_log_transport_write, \ + node), \ (n) = (transp)->node.next) LIBLOG_HIDDEN void __android_log_config_write(); +LIBLOG_HIDDEN void __android_log_config_write_close(); __END_DECLS diff --git a/liblog/fake_log_device.c b/liblog/fake_log_device.c index 957129ed9..1d7a157ae 100644 --- a/liblog/fake_log_device.c +++ b/liblog/fake_log_device.c @@ -612,7 +612,12 @@ static ssize_t logWritev(int fd, const struct iovec* vector, int count) bail: unlock(); - return vector[0].iov_len + vector[1].iov_len + vector[2].iov_len; + int len = 0; + for (i = 0; i < count; ++i) { + len += vector[i].iov_len; + } + return len; + error: unlock(); return -1; diff --git a/liblog/fake_writer.c b/liblog/fake_writer.c index dab8bc54e..2350673e1 100644 --- a/liblog/fake_writer.c +++ b/liblog/fake_writer.c @@ -46,9 +46,19 @@ static int fakeOpen() { int i; for (i = 0; i < LOG_ID_MAX; i++) { - char buf[sizeof("/dev/log_security")]; + /* + * Known maximum size string, plus an 8 character margin to deal with + * possible independent changes to android_log_id_to_name(). + */ + char buf[sizeof("/dev/log_security") + 8]; + if (logFds[i] >= 0) { + continue; + } snprintf(buf, sizeof(buf), "/dev/log_%s", android_log_id_to_name(i)); logFds[i] = fakeLogOpen(buf, O_WRONLY); + if (logFds[i] < 0) { + fprintf(stderr, "fakeLogOpen(%s, O_WRONLY) failed\n", buf); + } } return 0; } @@ -66,16 +76,28 @@ static int fakeWrite(log_id_t log_id, struct timespec *ts __unused, struct iovec *vec, size_t nr) { ssize_t ret; - int logFd; + size_t i; + int logFd, len; if (/*(int)log_id >= 0 &&*/ (int)log_id >= (int)LOG_ID_MAX) { - return -EBADF; + return -EINVAL; + } + + len = 0; + for (i = 0; i < nr; ++i) { + len += vec[i].iov_len; + } + + if (len > LOGGER_ENTRY_MAX_PAYLOAD) { + len = LOGGER_ENTRY_MAX_PAYLOAD; } logFd = logFds[(int)log_id]; ret = TEMP_FAILURE_RETRY(fakeLogWritev(logFd, vec, nr)); if (ret < 0) { ret = -errno; + } else if (ret > len) { + ret = len; } return ret; diff --git a/liblog/include/log/log_frontend.h b/liblog/include/log/log_frontend.h new file mode 100644 index 000000000..952777971 --- /dev/null +++ b/liblog/include/log/log_frontend.h @@ -0,0 +1,34 @@ +/* +** +** Copyright 2017, The Android Open Source Project +** +** This file is dual licensed. It may be redistributed and/or modified +** under the terms of the Apache 2.0 License OR version 2 of the GNU +** General Public License. +*/ + +#ifndef _LIBS_LOG_FRONTEND_H +#define _LIBS_LOG_FRONTEND_H + +#ifdef __cplusplus +extern "C" { +#endif + +/* + * Logging frontends, bit mask to select features. Function returns selection. + */ +#define LOGGER_DEFAULT 0x0 +#define LOGGER_LOGD 0x1 +#define LOGGER_KERNEL 0x2 /* Reserved/Deprecated */ +#define LOGGER_NULL 0x4 /* Does not release resources of other selections */ +#define LOGGER_LOCAL 0x8 /* logs sent to local memory */ + +/* Both return the selected frontend flag mask, or negative errno */ +int android_set_log_frontend(int frontend_flag); +int android_get_log_frontend(); + +#ifdef __cplusplus +} +#endif + +#endif /* _LIBS_LOG_FRONTEND_H */ diff --git a/liblog/include/log/log_radio.h b/liblog/include/log/log_radio.h index 30a73f267..430e5229b 100644 --- a/liblog/include/log/log_radio.h +++ b/liblog/include/log/log_radio.h @@ -38,6 +38,10 @@ /* --------------------------------------------------------------------- */ +#ifndef __predict_false +#define __predict_false(exp) __builtin_expect((exp) != 0, 0) +#endif + /* * Simplified macro to send a verbose radio log message using current LOG_TAG. */ diff --git a/liblog/include/log/log_read.h b/liblog/include/log/log_read.h index 5b5eebca6..6a44b5685 100644 --- a/liblog/include/log/log_read.h +++ b/liblog/include/log/log_read.h @@ -251,7 +251,11 @@ int android_logger_set_prune_list(struct logger_list* logger_list, #define ANDROID_LOG_WRONLY O_WRONLY #define ANDROID_LOG_RDWR O_RDWR #define ANDROID_LOG_ACCMODE O_ACCMODE +#ifndef O_NONBLOCK +#define ANDROID_LOG_NONBLOCK 0x00000800 +#else #define ANDROID_LOG_NONBLOCK O_NONBLOCK +#endif #if __ANDROID_USE_LIBLOG_READER_INTERFACE > 2 #define ANDROID_LOG_WRAP 0x40000000 /* Block until buffer about to wrap */ #define ANDROID_LOG_WRAP_DEFAULT_TIMEOUT 7200 /* 2 hour default */ diff --git a/liblog/include/log/log_system.h b/liblog/include/log/log_system.h index 8c1ec96e8..394a10645 100644 --- a/liblog/include/log/log_system.h +++ b/liblog/include/log/log_system.h @@ -36,6 +36,10 @@ #endif #endif +#ifndef __predict_false +#define __predict_false(exp) __builtin_expect((exp) != 0, 0) +#endif + /* * Simplified macro to send a verbose system log message using current LOG_TAG. */ diff --git a/liblog/local_logger.c b/liblog/local_logger.c new file mode 100644 index 000000000..d504342ea --- /dev/null +++ b/liblog/local_logger.c @@ -0,0 +1,556 @@ +/* + * Copyright (C) 2017 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 +#include +#include +#if !defined(__MINGW32__) +#include +#endif +#include +#include +#include +#include +#include + +#include /* template, no library dependency */ +#include +#include +#include +#include + +#include "config_read.h" +#include "config_write.h" +#include "log_portability.h" +#include "logger.h" + +static const char baseServiceName[] = "android.logd"; + +static int writeToLocalInit(); +static int writeToLocalAvailable(log_id_t logId); +static void writeToLocalReset(); +static int writeToLocalWrite(log_id_t logId, struct timespec *ts, + struct iovec *vec, size_t nr); + +LIBLOG_HIDDEN struct android_log_transport_write localLoggerWrite = { + .node = { &localLoggerWrite.node, &localLoggerWrite.node }, + .context.private = NULL, + .name = "local", + .available = writeToLocalAvailable, + .open = writeToLocalInit, + .close = writeToLocalReset, + .write = writeToLocalWrite, +}; + +static int writeToLocalVersion(struct android_log_logger *logger, + struct android_log_transport_context *transp); +static int writeToLocalRead(struct android_log_logger_list *logger_list, + struct android_log_transport_context *transp, + struct log_msg *log_msg); +static int writeToLocalPoll(struct android_log_logger_list *logger_list, + struct android_log_transport_context *transp); +static void writeToLocalClose(struct android_log_logger_list *logger_list, + struct android_log_transport_context *transp); +static int writeToLocalClear(struct android_log_logger *logger, + struct android_log_transport_context *transp); +static ssize_t writeToLocalGetSize( + struct android_log_logger *logger, + struct android_log_transport_context *transp); +static ssize_t writeToLocalSetSize( + struct android_log_logger *logger, + struct android_log_transport_context *transp __unused, + size_t size); +static ssize_t writeToLocalGetReadbleSize( + struct android_log_logger *logger, + struct android_log_transport_context *transp); + +struct android_log_transport_read localLoggerRead = { + .node = { &localLoggerRead.node, &localLoggerRead.node }, + .name = "local", + .available = writeToLocalAvailable, + .version = writeToLocalVersion, + .read = writeToLocalRead, + .poll = writeToLocalPoll, + .close = writeToLocalClose, + .clear = writeToLocalClear, + .getSize = writeToLocalGetSize, + .setSize = writeToLocalSetSize, + .getReadableSize = writeToLocalGetReadbleSize, + .getPrune = NULL, + .setPrune = NULL, + .getStats = NULL, +}; + +struct LogBufferElement { + struct listnode node; + log_id_t logId; + pid_t tid; + log_time timestamp; + unsigned short len; + char msg[]; +}; + +static const size_t MAX_SIZE_DEFAULT = 32768; + +/* + * Number of log buffers we support with the following assumption: + * . . . + * LOG_ID_SECURITY = 5, // security logs go to the system logs only + * LOG_ID_KERNEL = 6, // place last, third-parties can not use it + * LOG_ID_MAX + * } log_id_t; + * + * Confirm the following should be adjusted in the future. + */ +#define NUMBER_OF_LOG_BUFFERS ((LOG_ID_SECURITY == (LOG_ID_MAX - 2)) ? \ + LOG_ID_SECURITY : \ + LOG_ID_KERNEL) +#define BLOCK_LOG_BUFFERS(id) (((id) == LOG_ID_SECURITY) || \ + ((id) == LOG_ID_KERNEL)) + +static struct LogBuffer { + struct listnode head; + pthread_rwlock_t listLock; + char *serviceName; /* Also indicates ready by having a value */ + /* Order and proximity important for memset */ + size_t number[NUMBER_OF_LOG_BUFFERS]; /* clear memset */ + size_t size[NUMBER_OF_LOG_BUFFERS]; /* clear memset */ + size_t totalSize[NUMBER_OF_LOG_BUFFERS]; /* init memset */ + size_t maxSize[NUMBER_OF_LOG_BUFFERS]; /* init MAX_SIZE_DEFAULT */ + struct listnode *last[NUMBER_OF_LOG_BUFFERS]; /* init &head */ +} logbuf = { + .head = { &logbuf.head, &logbuf.head }, + .listLock = PTHREAD_RWLOCK_INITIALIZER, +}; + +static void LogBufferInit(struct LogBuffer *log) { + size_t i; + + pthread_rwlock_wrlock(&log->listLock); + list_init(&log->head); + memset(log->number, 0, + sizeof(log->number) + sizeof(log->size) + sizeof(log->totalSize)); + for (i = 0; i < NUMBER_OF_LOG_BUFFERS; ++i) { + log->maxSize[i] = MAX_SIZE_DEFAULT; + log->last[i] = &log->head; + } +#ifdef __BIONIC__ + asprintf(&log->serviceName, "%s@%d:%d", baseServiceName, + __android_log_uid(), getpid()); +#else + char buffer[sizeof(baseServiceName) + 1 + 5 + 1 + 5 + 8]; + snprintf(buffer, sizeof(buffer), "%s@%d:%d", baseServiceName, + __android_log_uid(), getpid()); + log->serviceName = strdup(buffer); +#endif + pthread_rwlock_unlock(&log->listLock); +} + +static void LogBufferClear(struct LogBuffer *log) { + size_t i; + struct listnode *node; + + pthread_rwlock_wrlock(&log->listLock); + memset(log->number, 0, sizeof(log->number) + sizeof(log->size)); + for (i = 0; i < NUMBER_OF_LOG_BUFFERS; ++i) { + log->last[i] = &log->head; + } + while ((node = list_head(&log->head)) != &log->head) { + struct LogBufferElement *element; + + element = node_to_item(node, struct LogBufferElement, node); + list_remove(node); + free(element); + } + pthread_rwlock_unlock(&log->listLock); +} + +static inline void LogBufferFree(struct LogBuffer *log) { + pthread_rwlock_wrlock(&log->listLock); + free(log->serviceName); + log->serviceName = NULL; + pthread_rwlock_unlock(&log->listLock); + LogBufferClear(log); +} + +static int LogBufferLog(struct LogBuffer *log, + struct LogBufferElement *element) { + log_id_t logId = element->logId; + + pthread_rwlock_wrlock(&log->listLock); + log->number[logId]++; + log->size[logId] += element->len; + log->totalSize[logId] += element->len; + /* prune entry(s) until enough space is available */ + if (log->last[logId] == &log->head) { + log->last[logId] = list_tail(&log->head); + } + while (log->size[logId] > log->maxSize[logId]) { + struct listnode *node = log->last[logId]; + struct LogBufferElement *e; + struct android_log_logger_list *logger_list; + + e = node_to_item(node, struct LogBufferElement, node); + log->number[logId]--; + log->size[logId] -= e->len; + logger_list_rdlock(); + logger_list_for_each(logger_list) { + struct android_log_transport_context *transp; + + transport_context_for_each(transp, logger_list) { + if ((transp->transport == &localLoggerRead) && + (transp->context.node == node)) { + if (node == &log->head) { + transp->context.node = &log->head; + } else { + transp->context.node = node->next; + } + } + } + } + logger_list_unlock(); + if (node != &log->head) { + log->last[logId] = node->prev; + } + list_remove(node); + free(e); + } + /* add entry to list */ + list_add_head(&log->head, &element->node); + /* ToDo: wake up all readers */ + pthread_rwlock_unlock(&log->listLock); + + return element->len; +} + +/* + * return zero if permitted to log directly to logd, + * return 1 if binder server started and + * return negative error number if failed to start binder server. + */ +static int writeToLocalInit() { + pthread_attr_t attr; + struct LogBuffer *log; + + if (writeToLocalAvailable(LOG_ID_MAIN) < 0) { + return -EPERM; + } + + log = &logbuf; + if (!log->serviceName) { + LogBufferInit(log); + } + + if (!log->serviceName) { + LogBufferFree(log); + return -ENOMEM; + } + + return EPERM; /* successful local-only logging */ +} + +static void writeToLocalReset() { + LogBufferFree(&logbuf); +} + +static int writeToLocalAvailable(log_id_t logId) { +#if !defined(__MINGW32__) + uid_t uid; +#endif + + if ((logId >= NUMBER_OF_LOG_BUFFERS) || BLOCK_LOG_BUFFERS(logId)) { + return -EINVAL; + } + + /* Android hard coded permitted, system goes to logd */ +#if !defined(__MINGW32__) + if (__android_log_frontend == LOGGER_DEFAULT) { + uid = __android_log_uid(); + if ((uid < AID_APP) && (getpwuid(uid) != NULL)) { + return -EPERM; + } + } +#endif + + /* ToDo: Ask package manager for LOGD permissions */ + /* Assume we do _not_ have permissions to go to LOGD, so must go local */ + return 0; +} + +static int writeToLocalWrite(log_id_t logId, struct timespec *ts, + struct iovec *vec, size_t nr) { + size_t len, i; + struct LogBufferElement *element; + + if ((logId >= NUMBER_OF_LOG_BUFFERS) || BLOCK_LOG_BUFFERS(logId)) { + return -EINVAL; + } + + len = 0; + for (i = 0; i < nr; ++i) { + len += vec[i].iov_len; + } + + if (len > LOGGER_ENTRY_MAX_PAYLOAD) { + len = LOGGER_ENTRY_MAX_PAYLOAD; + } + element = (struct LogBufferElement *)calloc(1, + sizeof(struct LogBufferElement) + len + 1); + if (!element) { + return errno ? -errno : -ENOMEM; + } + element->timestamp.tv_sec = ts->tv_sec; + element->timestamp.tv_nsec = ts->tv_nsec; +#ifdef __BIONIC__ + element->tid = gettid(); +#else + element->tid = getpid(); +#endif + element->logId = logId; + element->len = len; + + char *cp = element->msg; + for (i = 0; i < nr; ++i) { + size_t iov_len = vec[i].iov_len; + if (iov_len > len) { + iov_len = len; + } + memcpy(cp, vec[i].iov_base, iov_len); + len -= iov_len; + if (len == 0) { + break; + } + cp += iov_len; + } + + return LogBufferLog(&logbuf, element); +} + +static int writeToLocalVersion( + struct android_log_logger *logger __unused, + struct android_log_transport_context *transp __unused) { + return 3; +} + +/* within reader lock, serviceName already validated */ +static struct listnode *writeToLocalNode( + struct android_log_logger_list *logger_list, + struct android_log_transport_context *transp) { + struct listnode *node; + unsigned logMask; + unsigned int tail; + + node = transp->context.node; + if (node) { + return node; + } + + if (!logger_list->tail) { + return transp->context.node = &logbuf.head; + } + + logMask = transp->logMask; + tail = logger_list->tail; + + for (node = list_head(&logbuf.head); node != &logbuf.head; node = node->next) { + struct LogBufferElement *element; + log_id_t logId; + + element = node_to_item(node, struct LogBufferElement, node); + logId = element->logId; + + if ((logMask & (1 << logId)) && !--tail) { + node = node->next; + break; + } + } + return transp->context.node = node; +} + +static int writeToLocalRead( + struct android_log_logger_list *logger_list, + struct android_log_transport_context *transp, + struct log_msg *log_msg) { + int ret; + struct listnode *node; + unsigned logMask; + + pthread_rwlock_rdlock(&logbuf.listLock); + if (!logbuf.serviceName) { + pthread_rwlock_unlock(&logbuf.listLock); + return (logger_list->mode & ANDROID_LOG_NONBLOCK) ? -ENODEV : 0; + } + + logMask = transp->logMask; + + node = writeToLocalNode(logger_list, transp); + + ret = 0; + + while (node != list_head(&logbuf.head)) { + struct LogBufferElement *element; + log_id_t logId; + + node = node->prev; + element = node_to_item(node, struct LogBufferElement, node); + logId = element->logId; + + if (logMask & (1 << logId)) { + ret = log_msg->entry_v3.len = element->len; + log_msg->entry_v3.hdr_size = sizeof(log_msg->entry_v3); + log_msg->entry_v3.pid = getpid(); + log_msg->entry_v3.tid = element->tid; + log_msg->entry_v3.sec = element->timestamp.tv_sec; + log_msg->entry_v3.nsec = element->timestamp.tv_nsec; + log_msg->entry_v3.lid = logId; + memcpy(log_msg->entry_v3.msg, element->msg, ret); + ret += log_msg->entry_v3.hdr_size; + break; + } + } + + transp->context.node = node; + + /* ToDo: if blocking, and no entry, put reader to sleep */ + pthread_rwlock_unlock(&logbuf.listLock); + return ret; +} + +static int writeToLocalPoll( + struct android_log_logger_list *logger_list, + struct android_log_transport_context *transp) { + int ret = (logger_list->mode & ANDROID_LOG_NONBLOCK) ? -ENODEV : 0; + + pthread_rwlock_rdlock(&logbuf.listLock); + + if (logbuf.serviceName) { + unsigned logMask = transp->logMask; + struct listnode *node = writeToLocalNode(logger_list, transp); + + ret = (node != list_head(&logbuf.head)); + if (ret) { + do { + ret = !!(logMask & (1 << (node_to_item(node->prev, + struct LogBufferElement, + node))->logId)); + } while (!ret && ((node = node->prev) != list_head(&logbuf.head))); + } + + transp->context.node = node; + } + + pthread_rwlock_unlock(&logbuf.listLock); + + return ret; +} + +static void writeToLocalClose( + struct android_log_logger_list *logger_list __unused, + struct android_log_transport_context *transp) { + pthread_rwlock_wrlock(&logbuf.listLock); + transp->context.node = list_head(&logbuf.head); + pthread_rwlock_unlock(&logbuf.listLock); +} + +static int writeToLocalClear( + struct android_log_logger *logger, + struct android_log_transport_context *unused __unused) { + log_id_t logId = logger->logId; + struct listnode *node, *n; + + if ((logId >= NUMBER_OF_LOG_BUFFERS) || BLOCK_LOG_BUFFERS(logId)) { + return -EINVAL; + } + + pthread_rwlock_wrlock(&logbuf.listLock); + logbuf.number[logId] = 0; + logbuf.last[logId] = &logbuf.head; + list_for_each_safe(node, n, &logbuf.head) { + struct LogBufferElement *element; + element = node_to_item(node, struct LogBufferElement, node); + + if (logId == element->logId) { + struct android_log_logger_list *logger_list; + + logger_list_rdlock(); + logger_list_for_each(logger_list) { + struct android_log_transport_context *transp; + + transport_context_for_each(transp, logger_list) { + if ((transp->transport == &localLoggerRead) && + (transp->context.node == node)) { + transp->context.node = node->next; + } + } + } + logger_list_unlock(); + list_remove(node); + free(element); + } + } + + pthread_rwlock_unlock(&logbuf.listLock); + + return 0; +} + +static ssize_t writeToLocalGetSize( + struct android_log_logger *logger, + struct android_log_transport_context *transp __unused) { + ssize_t ret = -EINVAL; + log_id_t logId = logger->logId; + + if ((logId < NUMBER_OF_LOG_BUFFERS) && !BLOCK_LOG_BUFFERS(logId)) { + pthread_rwlock_rdlock(&logbuf.listLock); + ret = logbuf.maxSize[logId]; + pthread_rwlock_unlock(&logbuf.listLock); + } + + return ret; +} + +static ssize_t writeToLocalSetSize( + struct android_log_logger *logger, + struct android_log_transport_context *transp __unused, + size_t size) { + ssize_t ret = -EINVAL; + + if ((size > LOGGER_ENTRY_MAX_LEN) || (size < (4 * 1024 * 1024))) { + log_id_t logId = logger->logId; + if ((logId < NUMBER_OF_LOG_BUFFERS) || !BLOCK_LOG_BUFFERS(logId)) { + pthread_rwlock_wrlock(&logbuf.listLock); + ret = logbuf.maxSize[logId] = size; + pthread_rwlock_unlock(&logbuf.listLock); + } + } + + return ret; +} + +static ssize_t writeToLocalGetReadbleSize( + struct android_log_logger *logger, + struct android_log_transport_context *transp __unused) { + ssize_t ret = -EINVAL; + log_id_t logId = logger->logId; + + if ((logId < NUMBER_OF_LOG_BUFFERS) && !BLOCK_LOG_BUFFERS(logId)) { + pthread_rwlock_rdlock(&logbuf.listLock); + ret = logbuf.serviceName ? (ssize_t)logbuf.size[logId] : -EBADF; + pthread_rwlock_unlock(&logbuf.listLock); + } + + return ret; +} diff --git a/liblog/logger.h b/liblog/logger.h index d332c0325..d94cd1467 100644 --- a/liblog/logger.h +++ b/liblog/logger.h @@ -99,6 +99,7 @@ struct android_log_transport_read { }; struct android_log_logger_list { + struct listnode node; struct listnode logger; struct listnode transport; int mode; @@ -146,6 +147,41 @@ struct android_log_transport_context { (logp) = node_to_item((logp)->node.next, \ struct android_log_logger, node)) +/* + * Global list of log readers. + * + * Usage case: search out transport contexts for all readers + */ + +LIBLOG_HIDDEN struct listnode __android_log_readers; + +#if defined(_WIN32) +#define logger_list_rdlock() +#define logger_list_wrlock() +#define logger_list_unlock() +#else +LIBLOG_HIDDEN pthread_rwlock_t __android_log_readers_lock; + +#define logger_list_rdlock() pthread_rwlock_rdlock(&__android_log_readers_lock) +#define logger_list_wrlock() pthread_rwlock_wrlock(&__android_log_readers_lock) +#define logger_list_unlock() pthread_rwlock_unlock(&__android_log_readers_lock) +#endif + +/* Must be called with logger_list_rdlock() or logger_list_wrlock() held */ +#define logger_list_for_each(logger_list) \ + for ((logger_list) = node_to_item(&__android_log_readers, \ + struct android_log_logger_list, \ + node); \ + (logger_list) != node_to_item(&__android_log_readers, \ + struct android_log_logger_list, \ + node) && \ + (logger_list) != node_to_item((logger_list)->node.next, \ + struct android_log_logger_list, \ + node); \ + (logger_list) = node_to_item((logger_list)->node.next, \ + struct android_log_logger_list, \ + node)) + /* OS specific dribs and drabs */ #if defined(_WIN32) @@ -160,6 +196,8 @@ LIBLOG_HIDDEN void __android_log_lock(); LIBLOG_HIDDEN int __android_log_trylock(); LIBLOG_HIDDEN void __android_log_unlock(); +LIBLOG_HIDDEN int __android_log_frontend; + __END_DECLS #endif /* _LIBLOG_LOGGER_H__ */ diff --git a/liblog/logger_read.c b/liblog/logger_read.c index c3cb7adc1..7e50a23fe 100644 --- a/liblog/logger_read.c +++ b/liblog/logger_read.c @@ -228,6 +228,13 @@ LIBLOG_ABI_PUBLIC int android_logger_set_prune_list( LOGGER_LIST_FUNCTION(logger_list, -ENODEV, setPrune, buf, len); } +LIBLOG_HIDDEN struct listnode __android_log_readers = + { &__android_log_readers, &__android_log_readers }; +#if !defined(_WIN32) +LIBLOG_HIDDEN pthread_rwlock_t __android_log_readers_lock = + PTHREAD_RWLOCK_INITIALIZER; +#endif + LIBLOG_ABI_PUBLIC struct logger_list *android_logger_list_alloc( int mode, unsigned int tail, @@ -246,6 +253,10 @@ LIBLOG_ABI_PUBLIC struct logger_list *android_logger_list_alloc( logger_list->tail = tail; logger_list->pid = pid; + logger_list_wrlock(); + list_add_tail(&__android_log_readers, &logger_list->node); + logger_list_unlock(); + return (struct logger_list *)logger_list; } @@ -267,6 +278,10 @@ LIBLOG_ABI_PUBLIC struct logger_list *android_logger_list_alloc_time( logger_list->start = start; logger_list->pid = pid; + logger_list_wrlock(); + list_add_tail(&__android_log_readers, &logger_list->node); + logger_list_unlock(); + return (struct logger_list *)logger_list; } @@ -502,6 +517,10 @@ LIBLOG_ABI_PUBLIC void android_logger_list_free(struct logger_list *logger_list) return; } + logger_list_wrlock(); + list_remove(&logger_list_internal->node); + logger_list_unlock(); + while (!list_empty(&logger_list_internal->transport)) { struct listnode *node = list_head(&logger_list_internal->transport); struct android_log_transport_context *transp = diff --git a/liblog/logger_write.c b/liblog/logger_write.c index 2599a5394..e149e682f 100644 --- a/liblog/logger_write.c +++ b/liblog/logger_write.c @@ -25,9 +25,11 @@ #endif #include +#include #include #include +#include "config_read.h" /* __android_log_config_read_close() definition */ #include "config_write.h" #include "log_portability.h" #include "logger.h" @@ -170,6 +172,8 @@ LIBLOG_ABI_PUBLIC void __android_log_close() } } + __android_log_config_write_close(); + #if defined(__ANDROID__) /* * Additional risk here somewhat mitigated by immediately unlock flushing @@ -618,3 +622,87 @@ LIBLOG_ABI_PUBLIC int __android_log_security_bswrite(int32_t tag, return write_to_log(LOG_ID_SECURITY, vec, 4); } + +static int __write_to_log_null(log_id_t log_id, struct iovec* vec, size_t nr) +{ + size_t len, i; + + if ((log_id < LOG_ID_MIN) || (log_id >= LOG_ID_MAX)) { + return -EINVAL; + } + + for (len = i = 0; i < nr; ++i) { + len += vec[i].iov_len; + } + if (!len) { + return -EINVAL; + } + return len; +} + +/* Following functions need access to our internal write_to_log status */ + +LIBLOG_HIDDEN int __android_log_frontend; + +LIBLOG_ABI_PUBLIC int android_set_log_frontend(int frontend_flag) +{ + int retval; + + if (frontend_flag < 0) { + return -EINVAL; + } + + retval = LOGGER_NULL; + + __android_log_lock(); + + if (frontend_flag & LOGGER_NULL) { + write_to_log = __write_to_log_null; + + __android_log_unlock(); + + return retval; + } + + __android_log_frontend &= LOGGER_LOCAL | LOGGER_LOGD; + + frontend_flag &= LOGGER_LOCAL | LOGGER_LOGD; + + if (__android_log_frontend != frontend_flag) { + __android_log_frontend = frontend_flag; + __android_log_config_write_close(); + __android_log_config_read_close(); + + write_to_log = __write_to_log_init; + /* generically we only expect these two values for write_to_log */ + } else if ((write_to_log != __write_to_log_init) && + (write_to_log != __write_to_log_daemon)) { + write_to_log = __write_to_log_init; + } + + retval = __android_log_frontend; + + __android_log_unlock(); + + return retval; +} + +LIBLOG_ABI_PUBLIC int android_get_log_frontend() +{ + int ret = LOGGER_DEFAULT; + + __android_log_lock(); + if (write_to_log == __write_to_log_null) { + ret = LOGGER_NULL; + } else { + __android_log_frontend &= LOGGER_LOCAL | LOGGER_LOGD; + ret = __android_log_frontend; + if ((write_to_log != __write_to_log_init) && + (write_to_log != __write_to_log_daemon)) { + ret = -EINVAL; + } + } + __android_log_unlock(); + + return ret; +} diff --git a/liblog/logprint.c b/liblog/logprint.c index 18af9dec0..e61850dc4 100644 --- a/liblog/logprint.c +++ b/liblog/logprint.c @@ -16,13 +16,20 @@ */ #define _GNU_SOURCE /* for asprintf */ +#ifndef __MINGW32__ +#define HAVE_STRSEP +#endif -#include +//#ifndef __MINGW32__ +//#include +//#endif #include #include #include #include +#ifndef __MINGW32__ #include +#endif #include #include #include @@ -40,6 +47,10 @@ #define MS_PER_NSEC 1000000 #define US_PER_NSEC 1000 +#ifndef MIN +#define MIN(a,b) (((a) < (b)) ? (a) : (b)) +#endif + typedef struct FilterInfo_t { char *mTag; android_LogPriority mPri; @@ -216,7 +227,11 @@ LIBLOG_ABI_PUBLIC AndroidLogFormat *android_log_format_new() p_ret->year_output = false; p_ret->zone_output = false; p_ret->epoch_output = false; +#ifdef __ANDROID__ p_ret->monotonic_output = android_log_clockid() == CLOCK_MONOTONIC; +#else + p_ret->monotonic_output = false; +#endif p_ret->uid_output = false; p_ret->descriptive_output = false; descriptive_output = false; @@ -322,6 +337,7 @@ LIBLOG_ABI_PUBLIC AndroidLogPrintFormat android_log_formatFromString( else if (strcmp(formatString, "monotonic") == 0) format = FORMAT_MODIFIER_MONOTONIC; else if (strcmp(formatString, "uid") == 0) format = FORMAT_MODIFIER_UID; else if (strcmp(formatString, "descriptive") == 0) format = FORMAT_MODIFIER_DESCRIPT; +#ifndef __MINGW32__ else { extern char *tzname[2]; static const char gmt[] = "GMT"; @@ -353,6 +369,7 @@ LIBLOG_ABI_PUBLIC AndroidLogPrintFormat android_log_formatFromString( } free(cp); } +#endif return format; } @@ -411,7 +428,7 @@ LIBLOG_ABI_PUBLIC int android_log_addFilterRule( /* * Presently HAVE_STRNDUP is never defined, so the second case is always taken - * Darwin doesn't have strnup, everything else does + * Darwin doesn't have strndup, everything else does */ #ifdef HAVE_STRNDUP tagName = strndup(filterExpression, tagNameLength); @@ -433,6 +450,27 @@ error: return -1; } +#ifndef HAVE_STRSEP +/* KISS replacement helper for below */ +static char* strsep(char** stringp, const char* delim) +{ + char* token; + char* ret = *stringp; + + if (!ret || !*ret) { + return NULL; + } + token = strpbrk(ret, delim); + if (token) { + *token = '\0'; + ++token; + } else { + token = ret + strlen(ret); + } + *stringp = token; + return ret; +} +#endif /** * filterString: a comma/whitespace-separated set of filter expressions @@ -444,7 +482,6 @@ error: * Assumes single threaded execution * */ - LIBLOG_ABI_PUBLIC int android_log_addFilterString( AndroidLogFormat *p_format, const char *filterString) @@ -728,6 +765,7 @@ static int android_log_printBinaryEvent(const unsigned char** pEventData, } } } + outCount = 0; lval = 0; switch (type) { case EVENT_TYPE_INT: @@ -953,7 +991,7 @@ no_room: LIBLOG_ABI_PUBLIC int android_log_processBinaryLogBuffer( struct logger_entry *buf, AndroidLogEntry *entry, - const EventTagMap *map, + const EventTagMap *map __unused, char *messageBuf, int messageBufLen) { size_t inCount; @@ -995,11 +1033,12 @@ LIBLOG_ABI_PUBLIC int android_log_processBinaryLogBuffer( inCount -= 4; entry->tagLen = 0; + entry->tag = NULL; +#ifdef __ANDROID__ if (map != NULL) { entry->tag = android_lookupEventTag_len(map, &entry->tagLen, tagIndex); - } else { - entry->tag = NULL; } +#endif /* * If we don't have a map, or didn't find the tag number in the map, @@ -1024,9 +1063,11 @@ LIBLOG_ABI_PUBLIC int android_log_processBinaryLogBuffer( */ const char* fmtStr = NULL; size_t fmtLen = 0; +#ifdef __ANDROID__ if (descriptive_output && map) { fmtStr = android_lookupEventFormat_len(map, &fmtLen, tagIndex); } +#endif char* outBuf = messageBuf; size_t outRemaining = messageBufLen - 1; /* leave one for nul byte */ @@ -1250,6 +1291,7 @@ static long long nsecTimespec(struct timespec *now) return (long long)now->tv_sec * NS_PER_SEC + now->tv_nsec; } +#ifdef __ANDROID__ static void convertMonotonic(struct timespec *result, const AndroidLogEntry *entry) { @@ -1482,6 +1524,7 @@ static void convertMonotonic(struct timespec *result, result->tv_nsec = entry->tv_nsec; subTimespec(result, result, &convert); } +#endif /** * Formats a log message into a buffer @@ -1529,6 +1572,7 @@ LIBLOG_ABI_PUBLIC char *android_log_formatLogLine ( */ now = entry->tv_sec; nsec = entry->tv_nsec; +#if __ANDROID__ if (p_format->monotonic_output) { // prevent convertMonotonic from being called if logd is monotonic if (android_log_clockid() != CLOCK_MONOTONIC) { @@ -1538,6 +1582,7 @@ LIBLOG_ABI_PUBLIC char *android_log_formatLogLine ( nsec = time.tv_nsec; } } +#endif if (now < 0) { nsec = NS_PER_SEC - nsec; } @@ -1591,13 +1636,18 @@ LIBLOG_ABI_PUBLIC char *android_log_formatLogLine ( * This code is Android specific, bionic guarantees that * calls to non-reentrant getpwuid() are thread safe. */ +#if !defined(__MINGW32__) +#if (FAKE_LOG_DEVICE == 0) #ifndef __BIONIC__ #warning "This code assumes that getpwuid is thread safe, only true with Bionic!" +#endif #endif struct passwd* pwd = getpwuid(entry->uid); if (pwd && (strlen(pwd->pw_name) <= 5)) { snprintf(uid, sizeof(uid), "%5s:", pwd->pw_name); - } else { + } else +#endif + { // Not worth parsing package list, names all longer than 5 snprintf(uid, sizeof(uid), "%5d:", entry->uid); } diff --git a/liblog/tests/Android.mk b/liblog/tests/Android.mk index 097befc6d..cfea45202 100644 --- a/liblog/tests/Android.mk +++ b/liblog/tests/Android.mk @@ -55,7 +55,8 @@ test_c_flags := \ -fno-builtin \ test_src_files := \ - liblog_test.cpp \ + liblog_test_default.cpp \ + liblog_test_local.cpp \ log_id_test.cpp \ log_radio_test.cpp \ log_read_test.cpp \ @@ -111,6 +112,7 @@ LOCAL_MODULE_STEM_64 := $(LOCAL_MODULE)64 LOCAL_CXX_STL := libc++ LOCAL_SHARED_LIBRARIES := liblog libcutils libbase LOCAL_ADDITIONAL_DEPENDENCIES := $(LOCAL_PATH)/Android.mk +LOCAL_LDLIBS_linux := -lrt include $(BUILD_HOST_NATIVE_TEST) endif # ifeq ($(HOST_OS)-$(HOST_ARCH),$(filter $(HOST_OS)-$(HOST_ARCH),linux-x86 linux-x86_64)) diff --git a/liblog/tests/liblog_benchmark.cpp b/liblog/tests/liblog_benchmark.cpp index dc411c326..dac84ebe2 100644 --- a/liblog/tests/liblog_benchmark.cpp +++ b/liblog/tests/liblog_benchmark.cpp @@ -27,6 +27,7 @@ #include #include #include +#include #include #include "benchmark.h" @@ -80,10 +81,29 @@ static void BM_log_maximum(int iters) { } BENCHMARK(BM_log_maximum); +static void set_log_null() { + android_set_log_frontend(LOGGER_NULL); +} + +static void set_log_default() { + android_set_log_frontend(LOGGER_DEFAULT); +} + +static void BM_log_maximum_null(int iters) { + set_log_null(); + BM_log_maximum(iters); + set_log_default(); +} +BENCHMARK(BM_log_maximum_null); + /* - * Measure the time it takes to submit the android logging call using - * discrete acquisition under light load. Expect this to be a pair of - * syscall periods (2us). + * Measure the time it takes to collect the time using + * discrete acquisition (StartBenchmarkTiming() -> StopBenchmarkTiming()) + * under light load. Expect this to be a syscall period (2us) or + * data read time if zero-syscall. + * + * vdso support in the kernel and the library can allow + * clock_gettime to be zero-syscall. */ static void BM_clock_overhead(int iters) { for (int i = 0; i < iters; ++i) { @@ -468,19 +488,94 @@ static void BM_pmsg_long_unaligned1(int iters) { BENCHMARK(BM_pmsg_long_unaligned1); /* - * Measure the time it takes to submit the android logging call using - * discrete acquisition under light load. Expect this to be a dozen or so - * syscall periods (40us). + * Measure the time it takes to form sprintf plus time using + * discrete acquisition (StartBenchmarkTiming() -> StopBenchmarkTiming()) + * under light load. Expect this to be a syscall period (2us) or sprintf + * time if zero-syscall time. */ -static void BM_log_overhead(int iters) { +/* helper function */ +static void test_print(const char *fmt, ...) { + va_list ap; + char buf[1024]; + + va_start(ap, fmt); + vsnprintf(buf, sizeof(buf), fmt, ap); + va_end(ap); +} + +#define logd_yield() sched_yield() // allow logd to catch up +#define logd_sleep() usleep(50) // really allow logd to catch up + +/* performance test */ +static void BM_sprintf_overhead(int iters) { + for (int i = 0; i < iters; ++i) { + StartBenchmarkTiming(); + test_print("BM_sprintf_overhead:%d", i); + StopBenchmarkTiming(); + logd_yield(); + } +} +BENCHMARK(BM_sprintf_overhead); + +/* + * Measure the time it takes to submit the android printing logging call + * using discrete acquisition discrete acquisition (StartBenchmarkTiming() -> + * StopBenchmarkTiming()) under light load. Expect this to be a dozen or so + * syscall periods (40us) plus time to run *printf + */ +static void BM_log_print_overhead(int iters) { for (int i = 0; i < iters; ++i) { StartBenchmarkTiming(); __android_log_print(ANDROID_LOG_INFO, "BM_log_overhead", "%d", i); StopBenchmarkTiming(); - usleep(1000); + logd_yield(); } } -BENCHMARK(BM_log_overhead); +BENCHMARK(BM_log_print_overhead); + +/* + * Measure the time it takes to submit the android event logging call + * using discrete acquisition (StartBenchmarkTiming() -> StopBenchmarkTiming()) + * under light load. Expect this to be a dozen or so syscall periods (40us) + */ +static void BM_log_event_overhead(int iters) { + for (unsigned long long i = 0; i < (unsigned)iters; ++i) { + StartBenchmarkTiming(); + __android_log_btwrite(0, EVENT_TYPE_LONG, &i, sizeof(i)); + StopBenchmarkTiming(); + logd_yield(); + } +} +BENCHMARK(BM_log_event_overhead); + +static void BM_log_event_overhead_null(int iters) { + set_log_null(); + BM_log_event_overhead(iters); + set_log_default(); +} +BENCHMARK(BM_log_event_overhead_null); + +/* + * Measure the time it takes to submit the android event logging call + * using discrete acquisition (StartBenchmarkTiming() -> StopBenchmarkTiming()) + * under very-light load (<1% CPU utilization). + */ +static void BM_log_light_overhead(int iters) { + for (unsigned long long i = 0; i < (unsigned)iters; ++i) { + StartBenchmarkTiming(); + __android_log_btwrite(0, EVENT_TYPE_LONG, &i, sizeof(i)); + StopBenchmarkTiming(); + usleep(10000); + } +} +BENCHMARK(BM_log_light_overhead); + +static void BM_log_light_overhead_null(int iters) { + set_log_null(); + BM_log_light_overhead(iters); + set_log_default(); +} +BENCHMARK(BM_log_light_overhead_null); static void caught_latency(int /*signum*/) { diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp index 5faf8e162..bc0ea4c25 100644 --- a/liblog/tests/liblog_test.cpp +++ b/liblog/tests/liblog_test.cpp @@ -37,9 +37,32 @@ #include #include #include +#include #include #include +#ifndef TEST_PREFIX +#ifdef __ANDROID__ // make sure we always run code if compiled for android +#define TEST_PREFIX +#endif +#endif + +#if (!defined(USING_LOGGER_DEFAULT) || !defined(USING_LOGGER_LOCAL)) +#ifdef liblog // a binary clue that we are overriding the test names +// Does not support log reading blocking feature yet +// Does not support LOG_ID_SECURITY (unless we set LOGGER_LOCAL | LOGGER_LOGD) +// Assume some common aspects are tested by USING_LOGGER_DEFAULT: +// Does not need to _retest_ pmsg functionality +// Does not need to _retest_ property handling as it is a higher function +// Does not need to _retest_ event mapping functionality +// Does not need to _retest_ ratelimit +// Does not need to _retest_ logprint +#define USING_LOGGER_LOCAL +#else +#define USING_LOGGER_DEFAULT +#endif +#endif + // enhanced version of LOG_FAILURE_RETRY to add support for EAGAIN and // non-syscall libs. Since we are only using this in the emergency of // a signal to stuff a terminating code into the logs, we will spin rather @@ -56,7 +79,9 @@ _rc; }) TEST(liblog, __android_log_btwrite) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX +#endif int intBuf = 0xDEADBEEF; EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_INT, @@ -71,13 +96,10 @@ TEST(liblog, __android_log_btwrite) { EVENT_TYPE_STRING, Buf, sizeof(Buf) - 1)); usleep(1000); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } -#ifdef __ANDROID__ -std::string popenToString(std::string command) { +#if (defined(__ANDROID__) && !defined(USING_LOGGER_LOCAL)) +static std::string popenToString(std::string command) { std::string ret; FILE* fp = popen(command.c_str(), "r"); @@ -141,11 +163,11 @@ static bool isLogdwActive() { return false; } -bool tested__android_log_close; +static bool tested__android_log_close; #endif TEST(liblog, __android_log_btwrite__android_logger_list_read) { -#ifdef __ANDROID__ +#if (defined(__ANDROID__) || defined(USING_LOGGER_LOCAL)) struct logger_list *logger_list; pid_t pid = getpid(); @@ -153,9 +175,10 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); - // Check that we can close and reopen the logger log_time ts(CLOCK_MONOTONIC); ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); +#ifndef USING_LOGGER_LOCAL + // Check that we can close and reopen the logger bool pmsgActiveAfter__android_log_btwrite; bool logdwActiveAfter__android_log_btwrite; if (getuid() == AID_ROOT) { @@ -174,15 +197,18 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { EXPECT_FALSE(pmsgActiveAfter__android_log_close); EXPECT_FALSE(logdwActiveAfter__android_log_close); } +#endif log_time ts1(CLOCK_MONOTONIC); ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts1, sizeof(ts1))); +#ifndef USING_LOGGER_LOCAL if (getuid() == AID_ROOT) { pmsgActiveAfter__android_log_btwrite = isPmsgActive(); logdwActiveAfter__android_log_btwrite = isLogdwActive(); EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite); EXPECT_TRUE(logdwActiveAfter__android_log_btwrite); } +#endif usleep(1000000); int count = 0; @@ -225,15 +251,92 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { #endif } -#ifdef __ANDROID__ -static inline int32_t get4LE(const char* src) -{ +// This test makes little sense standalone, and requires the tests ahead +// and behind us, to make us whole. We could incorporate a prefix and +// suffix test to make this standalone, but opted to not complicate this. +TEST(liblog, android_set_log_frontend) { +#if (defined(__ANDROID__) || defined(USING_LOGGER_LOCAL)) +#ifdef TEST_PREFIX + TEST_PREFIX +#endif + + int logger = android_get_log_frontend(); + EXPECT_NE(LOGGER_NULL, logger); + + EXPECT_EQ(LOGGER_NULL, android_set_log_frontend(LOGGER_NULL)); + EXPECT_EQ(LOGGER_NULL, android_get_log_frontend()); + + pid_t pid = getpid(); + + struct logger_list *logger_list; + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( + LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); + + log_time ts(CLOCK_MONOTONIC); + ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); + + usleep(1000000); + + int count = 0; + + for (;;) { + log_msg log_msg; + if (android_logger_list_read(logger_list, &log_msg) <= 0) { + break; + } + + ASSERT_EQ(log_msg.entry.pid, pid); + + if ((log_msg.entry.len != sizeof(android_log_event_long_t)) + || (log_msg.id() != LOG_ID_EVENTS)) { + continue; + } + + android_log_event_long_t* eventData; + eventData = reinterpret_cast(log_msg.msg()); + + if (!eventData || (eventData->payload.type != EVENT_TYPE_LONG)) { + continue; + } + + log_time tx(reinterpret_cast(&eventData->payload.data)); + if (ts == tx) { + ++count; + } + } + + android_logger_list_close(logger_list); + + EXPECT_EQ(logger, android_set_log_frontend(logger)); + EXPECT_EQ(logger, android_get_log_frontend()); + + // False negative if liblog.__android_log_btwrite__android_logger_list_read + // fails above, so we will likely succeed. But we will have so many + // failures elsewhere that it is probably not worthwhile for us to + // highlight yet another disappointment. + EXPECT_EQ(0, count); + // We also expect failures in the following tests if the set does not + // react in an appropriate manner internally, yet passes, so we depend + // on this test being in the middle of a series of tests performed in + // the same process. +#else + GTEST_LOG_(INFO) << "This test does nothing.\n"; +#endif +} + +#ifdef TEST_PREFIX +static inline uint32_t get4LE(const uint8_t* src) { return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24); } + +static inline uint32_t get4LE(const char* src) { + return get4LE(reinterpret_cast(src)); +} #endif static void bswrite_test(const char *message) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX struct logger_list *logger_list; pid_t pid = getpid(); @@ -241,7 +344,11 @@ static void bswrite_test(const char *message) { ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); +#ifdef __ANDROID__ log_time ts(android_log_clockid()); +#else + log_time ts(CLOCK_REALTIME); +#endif ASSERT_LT(0, __android_log_bswrite(0, message)); size_t num_lines = 1, size = 0, length = 0, total = 0; @@ -307,8 +414,11 @@ static void bswrite_test(const char *message) { &log_msg.entry_v1, &entry, NULL, msgBuf, sizeof(msgBuf)); EXPECT_EQ((length == total) ? 0 : -1, processBinaryLogBuffer); if (processBinaryLogBuffer == 0) { + size_t line_overhead = 20; + if (pid > 99999) ++line_overhead; + if (pid > 999999) ++line_overhead; fflush(stderr); - EXPECT_EQ((int)((20 * num_lines) + size), + EXPECT_EQ((int)((line_overhead * num_lines) + size), android_log_printLogLine(logformat, fileno(stderr), &entry)); } android_log_format_free(logformat); @@ -345,7 +455,8 @@ TEST(liblog, __android_log_bswrite_and_print__multiple_newline) { } static void buf_write_test(const char *message) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX struct logger_list *logger_list; pid_t pid = getpid(); @@ -354,7 +465,11 @@ static void buf_write_test(const char *message) { LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); static const char tag[] = "TEST__android_log_buf_write"; +#ifdef __ANDROID__ log_time ts(android_log_clockid()); +#else + log_time ts(CLOCK_REALTIME); +#endif EXPECT_LT(0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO, tag, message)); @@ -402,8 +517,11 @@ static void buf_write_test(const char *message) { &entry); EXPECT_EQ(0, processLogBuffer); if (processLogBuffer == 0) { + size_t line_overhead = 11; + if (pid > 99999) ++line_overhead; + if (pid > 999999) ++line_overhead; fflush(stderr); - EXPECT_EQ((int)(((11 + sizeof(tag)) * num_lines) + size), + EXPECT_EQ((int)(((line_overhead + sizeof(tag)) * num_lines) + size), android_log_printLogLine(logformat, fileno(stderr), &entry)); } android_log_format_free(logformat); @@ -430,7 +548,8 @@ TEST(liblog, __android_log_buf_write_and_print__newline_space_prefix) { buf_write_test("\n Hello World \n"); } -#ifdef __ANDROID__ +#ifndef USING_LOGGER_LOCAL // requires blocking reader functionality +#ifdef TEST_PREFIX static unsigned signaled; static log_time signal_time; @@ -492,7 +611,8 @@ static void get_ticks(unsigned long long *uticks, unsigned long long *sticks) #endif TEST(liblog, android_logger_list_read__cpu_signal) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX struct logger_list *logger_list; unsigned long long v = 0xDEADBEEFA55A0000ULL; @@ -584,7 +704,7 @@ TEST(liblog, android_logger_list_read__cpu_signal) { #endif } -#ifdef __ANDROID__ +#ifdef TEST_PREFIX /* * Strictly, we are not allowed to log messages in a signal context, the * correct way to handle this is to ensure the messages are constructed in @@ -618,7 +738,7 @@ static void *running_thread(void *) { return NULL; } -int start_thread() +static int start_thread() { sem_init(&thread_trigger, 0, 0); @@ -650,7 +770,8 @@ int start_thread() #endif TEST(liblog, android_logger_list_read__cpu_thread) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX struct logger_list *logger_list; unsigned long long v = 0xDEADBEAFA55A0000ULL; @@ -742,8 +863,9 @@ TEST(liblog, android_logger_list_read__cpu_thread) { GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#endif // !USING_LOGGER_LOCAL -#ifdef __ANDROID__ +#ifdef TEST_PREFIX static const char max_payload_tag[] = "TEST_max_payload_and_longish_tag_XXXX"; #define SIZEOF_MAX_PAYLOAD_BUF (LOGGER_ENTRY_MAX_PAYLOAD - \ sizeof(max_payload_tag) - 1) @@ -880,7 +1002,8 @@ when you depart from me, sorrow abides and happiness\n\ takes his leave."; TEST(liblog, max_payload) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX pid_t pid = getpid(); char tag[sizeof(max_payload_tag)]; memcpy(tag, max_payload_tag, sizeof(tag)); @@ -944,7 +1067,8 @@ TEST(liblog, max_payload) { } TEST(liblog, __android_log_buf_print__maxtag) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX struct logger_list *logger_list; pid_t pid = getpid(); @@ -952,7 +1076,11 @@ TEST(liblog, __android_log_buf_print__maxtag) { ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); +#ifdef __ANDROID__ log_time ts(android_log_clockid()); +#else + log_time ts(CLOCK_REALTIME); +#endif EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, max_payload_buf, max_payload_buf)); @@ -1004,7 +1132,8 @@ TEST(liblog, __android_log_buf_print__maxtag) { } TEST(liblog, too_big_payload) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX pid_t pid = getpid(); static const char big_payload_tag[] = "TEST_big_payload_XXXX"; char tag[sizeof(big_payload_tag)]; @@ -1058,6 +1187,12 @@ TEST(liblog, too_big_payload) { EXPECT_LE(LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag), static_cast(max_len)); + // SLOP: Allow the underlying interface to optionally place a + // terminating nul at the LOGGER_ENTRY_MAX_PAYLOAD's last byte + // or not. + if (ret == (max_len + static_cast(sizeof(big_payload_tag)) - 1)) { + --max_len; + } EXPECT_EQ(ret, max_len + static_cast(sizeof(big_payload_tag))); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -1065,17 +1200,29 @@ TEST(liblog, too_big_payload) { } TEST(liblog, dual_reader) { -#ifdef __ANDROID__ - struct logger_list *logger_list1; +#ifdef TEST_PREFIX + TEST_PREFIX - // >25 messages due to liblog.__android_log_buf_print__concurrentXX above. + static const int num = 25; + + for (int i = 25; i > 0; --i) { + static const char fmt[] = "dual_reader %02d"; + char buffer[sizeof(fmt) + 8]; + snprintf(buffer, sizeof(buffer), fmt, i); + LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_MAIN, + ANDROID_LOG_INFO, + "liblog", buffer)); + } + usleep(1000000); + + struct logger_list *logger_list1; ASSERT_TRUE(NULL != (logger_list1 = android_logger_list_open( - LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 25, 0))); + LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, num, 0))); struct logger_list *logger_list2; if (NULL == (logger_list2 = android_logger_list_open( - LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 15, 0))) { + LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, num - 10, 0))) { android_logger_list_close(logger_list1); ASSERT_TRUE(NULL != logger_list2); } @@ -1108,22 +1255,20 @@ TEST(liblog, dual_reader) { android_logger_list_close(logger_list1); android_logger_list_close(logger_list2); - EXPECT_EQ(25, count1); - EXPECT_EQ(15, count2); + EXPECT_EQ(num, count1); + EXPECT_EQ(num - 10, count2); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } -#ifdef __ANDROID__ +#ifndef USING_LOGGER_LOCAL // Do not retest logprint static bool checkPriForTag(AndroidLogFormat *p_format, const char *tag, android_LogPriority pri) { return android_log_shouldPrintLine(p_format, tag, pri) && !android_log_shouldPrintLine(p_format, tag, (android_LogPriority)(pri - 1)); } -#endif TEST(liblog, filterRule) { -#ifdef __ANDROID__ static const char tag[] = "random"; AndroidLogFormat *p_format = android_log_format_new(); @@ -1185,11 +1330,10 @@ TEST(liblog, filterRule) { #endif android_log_format_free(p_format); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } +#endif // !USING_LOGGER_LOCAL +#ifndef USING_LOGGER_LOCAL // Do not retest property handling TEST(liblog, is_loggable) { #ifdef __ANDROID__ static const char tag[] = "is_loggable"; @@ -1488,8 +1632,13 @@ TEST(liblog, is_loggable) { GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#endif // !USING_LOGGER_LOCAL -#ifdef __ANDROID__ +// Following tests the specific issues surrounding error handling wrt logd. +// Kills logd and toss all collected data, equivalent to logcat -b all -c, +// except we also return errors to the logging callers. +#ifndef USING_LOGGER_LOCAL +#ifdef TEST_PREFIX // helper to liblog.enoent to count end-to-end matching logging messages. static int count_matching_ts(log_time ts) { usleep(1000000); @@ -1531,10 +1680,11 @@ static testing::AssertionResult IsOk(bool ok, std::string &message) { testing::AssertionSuccess() : (testing::AssertionFailure() << message); } -#endif +#endif // TEST_PREFIX TEST(liblog, enoent) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX + TEST_PREFIX log_time ts(CLOCK_MONOTONIC); EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); EXPECT_EQ(1, count_matching_ts(ts)); @@ -1588,9 +1738,12 @@ TEST(liblog, enoent) { GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#endif // !USING_LOCAL_LOGGER // Below this point we run risks of setuid(AID_SYSTEM) which may affect others. +// Do not retest properties, and cannot log into LOG_ID_SECURITY +#ifndef USING_LOGGER_LOCAL TEST(liblog, __security) { #ifdef __ANDROID__ static const char persist_key[] = "persist.logd.security"; @@ -1776,15 +1929,19 @@ TEST(liblog, __security_buffer) { GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#endif // !USING_LOGGER_LOCAL -#ifdef __ANDROID__ +#ifdef TEST_PREFIX static void android_errorWriteWithInfoLog_helper(int TAG, const char* SUBTAG, int UID, const char* payload, int DATA_LEN, int& count) { + TEST_PREFIX struct logger_list *logger_list; pid_t pid = getpid(); + count = 0; + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); @@ -1798,8 +1955,6 @@ static void android_errorWriteWithInfoLog_helper(int TAG, const char* SUBTAG, sleep(2); - count = 0; - for (;;) { log_msg log_msg; if (android_logger_list_read(logger_list, &log_msg) <= 0) { @@ -1839,7 +1994,7 @@ static void android_errorWriteWithInfoLog_helper(int TAG, const char* SUBTAG, ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]); eventData++; - int subtag_len = strlen(SUBTAG); + unsigned subtag_len = strlen(SUBTAG); if (subtag_len > 32) subtag_len = 32; ASSERT_EQ(subtag_len, get4LE(eventData)); eventData += 4; @@ -1853,7 +2008,7 @@ static void android_errorWriteWithInfoLog_helper(int TAG, const char* SUBTAG, ASSERT_EQ(EVENT_TYPE_INT, eventData[0]); eventData++; - ASSERT_EQ(UID, get4LE(eventData)); + ASSERT_EQ(UID, (int)get4LE(eventData)); eventData += 4; // Element #3: string type for data @@ -1883,7 +2038,7 @@ static void android_errorWriteWithInfoLog_helper(int TAG, const char* SUBTAG, #endif TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__typical) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX int count; android_errorWriteWithInfoLog_helper( 123456781, @@ -1899,7 +2054,7 @@ TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__typical) { } TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__data_too_large) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX int count; android_errorWriteWithInfoLog_helper( 123456782, @@ -1915,7 +2070,7 @@ TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__data_too_l } TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__null_data) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX int count; android_errorWriteWithInfoLog_helper( 123456783, @@ -1931,7 +2086,7 @@ TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__null_data) } TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__subtag_too_long) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX int count; android_errorWriteWithInfoLog_helper( 123456784, @@ -1954,12 +2109,15 @@ TEST(liblog, __android_log_buf_write_and_print__max) { buf_write_test(max_payload_buf); } -#ifdef __ANDROID__ +#ifdef TEST_PREFIX static void android_errorWriteLog_helper(int TAG, const char *SUBTAG, int& count) { + TEST_PREFIX struct logger_list *logger_list; pid_t pid = getpid(); + count = 0; + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); @@ -1972,8 +2130,6 @@ static void android_errorWriteLog_helper(int TAG, const char *SUBTAG, int& count sleep(2); - count = 0; - for (;;) { log_msg log_msg; if (android_logger_list_read(logger_list, &log_msg) <= 0) { @@ -2011,7 +2167,7 @@ static void android_errorWriteLog_helper(int TAG, const char *SUBTAG, int& count ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]); eventData++; - ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData)); + ASSERT_EQ(strlen(SUBTAG), get4LE(eventData)); eventData +=4; if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) { @@ -2025,7 +2181,7 @@ static void android_errorWriteLog_helper(int TAG, const char *SUBTAG, int& count #endif TEST(liblog, android_errorWriteLog__android_logger_list_read__success) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX int count; android_errorWriteLog_helper(123456785, "test-subtag", count); EXPECT_EQ(1, count); @@ -2035,7 +2191,7 @@ TEST(liblog, android_errorWriteLog__android_logger_list_read__success) { } TEST(liblog, android_errorWriteLog__android_logger_list_read__null_subtag) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX int count; android_errorWriteLog_helper(123456786, NULL, count); EXPECT_EQ(0, count); @@ -2044,7 +2200,8 @@ TEST(liblog, android_errorWriteLog__android_logger_list_read__null_subtag) { #endif } -#ifdef __ANDROID__ +// Do not retest logger list handling +#if (defined(TEST_PREFIX) || !defined(USING_LOGGER_LOCAL)) static int is_real_element(int type) { return ((type == EVENT_TYPE_INT) || (type == EVENT_TYPE_LONG) || @@ -2052,8 +2209,8 @@ static int is_real_element(int type) { (type == EVENT_TYPE_FLOAT)); } -int android_log_buffer_to_string(const char *msg, size_t len, - char *strOut, size_t strOutLen) { +static int android_log_buffer_to_string(const char *msg, size_t len, + char *strOut, size_t strOutLen) { android_log_context context = create_android_log_parser(msg, len); android_log_list_element elem; bool overflow = false; @@ -2203,7 +2360,9 @@ int android_log_buffer_to_string(const char *msg, size_t len, return 0; } +#endif // TEST_PREFIX || !USING_LOGGER_LOCAL +#ifdef TEST_PREFIX static const char *event_test_int32(uint32_t tag, size_t &expected_len) { android_log_context ctx; @@ -2459,6 +2618,7 @@ static void print_barrier() { } static void create_android_logger(const char *(*fn)(uint32_t tag, size_t &expected_len)) { + TEST_PREFIX struct logger_list *logger_list; pid_t pid = getpid(); @@ -2466,7 +2626,11 @@ static void create_android_logger(const char *(*fn)(uint32_t tag, size_t &expect ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid))); +#ifdef __ANDROID__ log_time ts(android_log_clockid()); +#else + log_time ts(CLOCK_REALTIME); +#endif size_t expected_len; const char *expected_string = (*fn)(1005, expected_len); @@ -2507,18 +2671,23 @@ static void create_android_logger(const char *(*fn)(uint32_t tag, size_t &expect &log_msg.entry_v1, &entry, NULL, msgBuf, sizeof(msgBuf)); EXPECT_EQ(0, processBinaryLogBuffer); if (processBinaryLogBuffer == 0) { + int line_overhead = 20; + if (pid > 99999) ++line_overhead; + if (pid > 999999) ++line_overhead; print_barrier(); int printLogLine = android_log_printLogLine( logformat, fileno(stderr), &entry); print_barrier(); - EXPECT_EQ(20 + (int)strlen(expected_string), printLogLine); + EXPECT_EQ(line_overhead + (int)strlen(expected_string), + printLogLine); } android_log_format_free(logformat); // test buffer reading API int buffer_to_string = -1; if (eventData) { - snprintf(msgBuf, sizeof(msgBuf), "I/[%d]", get4LE(eventData)); + snprintf(msgBuf, sizeof(msgBuf), + "I/[%" PRIu32 "]", get4LE(eventData)); print_barrier(); fprintf(stderr, "%-10s(%5u): ", msgBuf, pid); memset(msgBuf, 0, sizeof(msgBuf)); @@ -2541,7 +2710,7 @@ static void create_android_logger(const char *(*fn)(uint32_t tag, size_t &expect #endif TEST(liblog, create_android_logger_int32) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_int32); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2549,7 +2718,7 @@ TEST(liblog, create_android_logger_int32) { } TEST(liblog, create_android_logger_int64) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_int64); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2557,7 +2726,7 @@ TEST(liblog, create_android_logger_int64) { } TEST(liblog, create_android_logger_list_int64) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_list_int64); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2565,7 +2734,7 @@ TEST(liblog, create_android_logger_list_int64) { } TEST(liblog, create_android_logger_simple_automagic_list) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_simple_automagic_list); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2573,7 +2742,7 @@ TEST(liblog, create_android_logger_simple_automagic_list) { } TEST(liblog, create_android_logger_list_empty) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_list_empty); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2581,7 +2750,7 @@ TEST(liblog, create_android_logger_list_empty) { } TEST(liblog, create_android_logger_complex_nested_list) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_complex_nested_list); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2589,7 +2758,7 @@ TEST(liblog, create_android_logger_complex_nested_list) { } TEST(liblog, create_android_logger_7_level_prefix) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_7_level_prefix); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2597,7 +2766,7 @@ TEST(liblog, create_android_logger_7_level_prefix) { } TEST(liblog, create_android_logger_7_level_suffix) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_7_level_suffix); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2605,7 +2774,7 @@ TEST(liblog, create_android_logger_7_level_suffix) { } TEST(liblog, create_android_logger_android_log_error_write) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_android_log_error_write); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; @@ -2613,15 +2782,15 @@ TEST(liblog, create_android_logger_android_log_error_write) { } TEST(liblog, create_android_logger_android_log_error_write_null) { -#ifdef __ANDROID__ +#ifdef TEST_PREFIX create_android_logger(event_test_android_log_error_write_null); #else GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#ifndef USING_LOGGER_LOCAL // Do not retest logger list handling TEST(liblog, create_android_logger_overflow) { -#ifdef __ANDROID__ android_log_context ctx; EXPECT_TRUE(NULL != (ctx = create_android_logger(1005))); @@ -2646,13 +2815,9 @@ TEST(liblog, create_android_logger_overflow) { EXPECT_GT(0, android_log_write_list_begin(ctx)); EXPECT_LE(0, android_log_destroy(&ctx)); ASSERT_TRUE(NULL == ctx); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } TEST(liblog, android_log_write_list_buffer) { -#ifdef __ANDROID__ __android_log_event_list ctx(1005); ctx << 1005 << "tag_def" << "(tag|1),(name|3),(format|3)"; std::string buffer(ctx); @@ -2663,11 +2828,10 @@ TEST(liblog, android_log_write_list_buffer) { EXPECT_EQ(android_log_buffer_to_string(buffer.data(), buffer.length(), msgBuf, sizeof(msgBuf)), 0); EXPECT_STREQ(msgBuf, "[1005,tag_def,(tag|1),(name|3),(format|3)]"); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } +#endif // !USING_LOGGER_LOCAL +#ifndef USING_LOGGER_LOCAL // Do not retest pmsg functionality #ifdef __ANDROID__ static const char __pmsg_file[] = "/data/william-shakespeare/MuchAdoAboutNothing.txt"; @@ -2730,8 +2894,8 @@ TEST(liblog, __android_log_pmsg_file_write) { } #ifdef __ANDROID__ -ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename, - const char *buf, size_t len, void *arg) { +static ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename, + const char *buf, size_t len, void *arg) { EXPECT_TRUE(NULL == arg); EXPECT_EQ(LOG_ID_CRASH, logId); EXPECT_EQ(ANDROID_LOG_VERBOSE, prio); @@ -2793,7 +2957,9 @@ TEST(liblog, __android_log_pmsg_file_read) { GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#endif // !USING_LOGGER_LOCAL +#ifndef USING_LOGGER_LOCAL // Do not retest event mapping functionality #ifdef __ANDROID__ // must be: ' 0 kB' static bool isZero(const std::string &content, std::string::size_type pos, @@ -2876,7 +3042,7 @@ static void event_log_tags_test_smap(pid_t pid) { EXPECT_TRUE(IsOk(private_ok, content)); EXPECT_TRUE(IsOk(anonymous_ok, content)); } -#endif +#endif // __ANDROID__ TEST(liblog, event_log_tags) { #ifdef __ANDROID__ @@ -2897,7 +3063,9 @@ TEST(liblog, event_log_tags) { GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#endif // !USING_LOGGER_LOCAL +#ifndef USING_LOGGER_LOCAL // Do not retest ratelimit TEST(liblog, __android_log_ratelimit) { time_t state = 0; @@ -2929,7 +3097,9 @@ TEST(liblog, __android_log_ratelimit) { } // Do not test default seconds, to allow liblog to tune freely } +#endif // !USING_LOGGER_LOCAL +#ifndef USING_LOGGER_LOCAL // Do not retest event mapping functionality TEST(liblog, android_lookupEventTagNum) { #ifdef __ANDROID__ EventTagMap* map = android_openEventTagMap(NULL); @@ -2945,3 +3115,4 @@ TEST(liblog, android_lookupEventTagNum) { GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif } +#endif // !USING_LOGGER_LOCAL diff --git a/liblog/tests/liblog_test_default.cpp b/liblog/tests/liblog_test_default.cpp new file mode 100644 index 000000000..079ba07ca --- /dev/null +++ b/liblog/tests/liblog_test_default.cpp @@ -0,0 +1,5 @@ +#ifdef __ANDROID__ +#include +#define TEST_PREFIX android_set_log_frontend(LOGGER_DEFAULT); +#endif +#include "liblog_test.cpp" diff --git a/liblog/tests/liblog_test_local.cpp b/liblog/tests/liblog_test_local.cpp new file mode 100644 index 000000000..5f7f645fc --- /dev/null +++ b/liblog/tests/liblog_test_local.cpp @@ -0,0 +1,4 @@ +#include +#define liblog liblog_local +#define TEST_PREFIX android_set_log_frontend(LOGGER_LOCAL); +#include "liblog_test.cpp" diff --git a/liblog/tests/log_id_test.cpp b/liblog/tests/log_id_test.cpp index 3241534f1..b8223f15d 100644 --- a/liblog/tests/log_id_test.cpp +++ b/liblog/tests/log_id_test.cpp @@ -31,7 +31,6 @@ #endif TEST(liblog, log_id) { -#ifdef __ANDROID__ int count = 0; for(int i = LOG_ID_MIN; i < LOG_ID_MAX; ++i) { @@ -44,13 +43,9 @@ TEST(liblog, log_id) { fprintf(stderr, "log buffer %s\r", name); } ASSERT_EQ(LOG_ID_MAX, count); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } TEST(liblog, __android_log_buf_print) { -#ifdef __ANDROID__ EXPECT_LT(0, __android_log_buf_print(LOG_ID_RADIO, ANDROID_LOG_INFO, "TEST__android_log_buf_print", "radio")); @@ -63,13 +58,9 @@ TEST(liblog, __android_log_buf_print) { "TEST__android_log_buf_print", "main")); usleep(1000); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } TEST(liblog, __android_log_buf_write) { -#ifdef __ANDROID__ EXPECT_LT(0, __android_log_buf_write(LOG_ID_RADIO, ANDROID_LOG_INFO, "TEST__android_log_buf_write", "radio")); @@ -82,26 +73,20 @@ TEST(liblog, __android_log_buf_write) { "TEST__android_log_buf_write", "main")); usleep(1000); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } -#ifdef __ANDROID__ static void* ConcurrentPrintFn(void *arg) { int ret = __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, "TEST__android_log_print", "Concurrent %" PRIuPTR, reinterpret_cast(arg)); return reinterpret_cast(ret); } -#endif #define NUM_CONCURRENT 64 #define _concurrent_name(a,n) a##__concurrent##n #define concurrent_name(a,n) _concurrent_name(a,n) TEST(liblog, concurrent_name(__android_log_buf_print, NUM_CONCURRENT)) { -#ifdef __ANDROID__ pthread_t t[NUM_CONCURRENT]; int i; for (i=0; i < NUM_CONCURRENT; i++) { @@ -119,7 +104,4 @@ TEST(liblog, concurrent_name(__android_log_buf_print, NUM_CONCURRENT)) { } } ASSERT_LT(0, ret); -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif } diff --git a/liblog/tests/log_radio_test.cpp b/liblog/tests/log_radio_test.cpp index 591748ab2..ecba777d0 100644 --- a/liblog/tests/log_radio_test.cpp +++ b/liblog/tests/log_radio_test.cpp @@ -27,7 +27,6 @@ #include TEST(liblog, RLOG) { -#ifdef __ANDROID__ static const char content[] = "log_radio.h"; static const char content_false[] = "log_radio.h false"; @@ -84,6 +83,7 @@ TEST(liblog, RLOG) { usleep(100000); RLOGE_IF(false, content_false); +#ifdef __ANDROID__ // give time for content to long-path through logger sleep(1); @@ -112,6 +112,6 @@ TEST(liblog, RLOG) { #endif #else - GTEST_LOG_(INFO) << "This test does nothing.\n"; + GTEST_LOG_(INFO) << "This test does not test end-to-end.\n"; #endif } diff --git a/liblog/tests/log_system_test.cpp b/liblog/tests/log_system_test.cpp index b62832ec6..40e3a630e 100644 --- a/liblog/tests/log_system_test.cpp +++ b/liblog/tests/log_system_test.cpp @@ -27,7 +27,6 @@ #include TEST(liblog, SLOG) { -#ifdef __ANDROID__ static const char content[] = "log_system.h"; static const char content_false[] = "log_system.h false"; @@ -84,6 +83,7 @@ TEST(liblog, SLOG) { usleep(100000); SLOGE_IF(false, content_false); +#ifdef __ANDROID__ // give time for content to long-path through logger sleep(1); @@ -112,6 +112,6 @@ TEST(liblog, SLOG) { #endif #else - GTEST_LOG_(INFO) << "This test does nothing.\n"; + GTEST_LOG_(INFO) << "This test does not test end-to-end.\n"; #endif } diff --git a/liblog/tests/log_time_test.cpp b/liblog/tests/log_time_test.cpp index f2601b6ee..59655ba43 100644 --- a/liblog/tests/log_time_test.cpp +++ b/liblog/tests/log_time_test.cpp @@ -21,8 +21,6 @@ #include TEST(liblog, log_time) { -#ifdef __ANDROID__ - #ifdef _SYSTEM_CORE_INCLUDE_PRIVATE_ANDROID_LOGGER_H_ log_time(CLOCK_MONOTONIC); @@ -36,8 +34,4 @@ TEST(liblog, log_time) { EXPECT_EQ(tl, ts); EXPECT_GE(tl, ts); EXPECT_LE(tl, ts); - -#else - GTEST_LOG_(INFO) << "This test does nothing.\n"; -#endif }