diff options
Diffstat (limited to 'liblog')
| -rw-r--r-- | liblog/Android.mk | 24 | ||||
| -rw-r--r-- | liblog/event_tag_map.c | 28 | ||||
| -rw-r--r-- | liblog/fake_log_device.c | 14 | ||||
| -rw-r--r-- | liblog/log_read.c | 857 | ||||
| -rw-r--r-- | liblog/log_read_kern.c | 741 | ||||
| -rw-r--r-- | liblog/log_time.cpp | 168 | ||||
| -rw-r--r-- | liblog/logd_write.c | 304 | ||||
| -rw-r--r-- | liblog/logd_write_kern.c | 341 | ||||
| -rw-r--r-- | liblog/logprint.c | 123 | ||||
| -rw-r--r-- | liblog/tests/Android.mk | 19 | ||||
| -rw-r--r-- | liblog/tests/benchmark_main.cpp | 5 | ||||
| -rw-r--r-- | liblog/tests/libc_test.cpp | 138 | ||||
| -rw-r--r-- | liblog/tests/liblog_benchmark.cpp | 6 | ||||
| -rw-r--r-- | liblog/tests/liblog_test.cpp | 423 |
14 files changed, 2549 insertions, 642 deletions
diff --git a/liblog/Android.mk b/liblog/Android.mk index 0d6c970..a7eead9 100644 --- a/liblog/Android.mk +++ b/liblog/Android.mk @@ -16,7 +16,11 @@ LOCAL_PATH := $(my-dir) include $(CLEAR_VARS) +ifneq ($(TARGET_USES_LOGD),false) liblog_sources := logd_write.c +else +liblog_sources := logd_write_kern.c +endif # some files must not be compiled when building against Mingw # they correspond to features not used by our host development tools @@ -42,19 +46,28 @@ else endif liblog_host_sources := $(liblog_sources) fake_log_device.c -liblog_target_sources = $(liblog_sources) log_read.c +liblog_target_sources := $(liblog_sources) log_time.cpp +ifneq ($(TARGET_USES_LOGD),false) +liblog_target_sources += log_read.c +else +liblog_target_sources += log_read_kern.c +endif # Shared and static library for host # ======================================================== LOCAL_MODULE := liblog LOCAL_SRC_FILES := $(liblog_host_sources) -LOCAL_LDLIBS := -lpthread -LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 +LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 -Werror +LOCAL_MULTILIB := both include $(BUILD_HOST_STATIC_LIBRARY) include $(CLEAR_VARS) LOCAL_MODULE := liblog LOCAL_WHOLE_STATIC_LIBRARIES := liblog +ifeq ($(strip $(HOST_OS)),linux) +LOCAL_LDLIBS := -lrt +endif +LOCAL_MULTILIB := both include $(BUILD_HOST_SHARED_LIBRARY) @@ -63,8 +76,7 @@ include $(BUILD_HOST_SHARED_LIBRARY) include $(CLEAR_VARS) LOCAL_MODULE := lib64log LOCAL_SRC_FILES := $(liblog_host_sources) -LOCAL_LDLIBS := -lpthread -LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 -m64 +LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 -m64 -Werror include $(BUILD_HOST_STATIC_LIBRARY) # Shared and static library for target @@ -72,11 +84,13 @@ include $(BUILD_HOST_STATIC_LIBRARY) include $(CLEAR_VARS) LOCAL_MODULE := liblog LOCAL_SRC_FILES := $(liblog_target_sources) +LOCAL_CFLAGS := -Werror include $(BUILD_STATIC_LIBRARY) include $(CLEAR_VARS) LOCAL_MODULE := liblog LOCAL_WHOLE_STATIC_LIBRARIES := liblog +LOCAL_CFLAGS := -Werror include $(BUILD_SHARED_LIBRARY) include $(call first-makefiles-under,$(LOCAL_PATH)) diff --git a/liblog/event_tag_map.c b/liblog/event_tag_map.c index f3d1e2f..bea99aa 100644 --- a/liblog/event_tag_map.c +++ b/liblog/event_tag_map.c @@ -13,15 +13,16 @@ * See the License for the specific language governing permissions and * limitations under the License. */ -#include <log/event_tag_map.h> -#include <log/log.h> +#include <assert.h> +#include <errno.h> +#include <fcntl.h> #include <stdlib.h> #include <string.h> -#include <fcntl.h> #include <sys/mman.h> -#include <errno.h> -#include <assert.h> + +#include <log/event_tag_map.h> +#include <log/log.h> #define OUT_TAG "EventTagMap" @@ -52,7 +53,6 @@ static int countMapLines(const EventTagMap* map); static int parseMapLines(EventTagMap* map); static int scanTagLine(char** pData, EventTag* tag, int lineNum); static int sortTags(EventTagMap* map); -static void dumpTags(const EventTagMap* map); /* @@ -185,8 +185,6 @@ static inline int isCharDigit(char c) */ static int processFile(EventTagMap* map) { - EventTag* tagArray = NULL; - /* get a tag count */ map->numTags = countMapLines(map); if (map->numTags < 0) @@ -422,17 +420,3 @@ static int sortTags(EventTagMap* map) return 0; } - -/* - * Dump the tag array for debugging. - */ -static void dumpTags(const EventTagMap* map) -{ - int i; - - for (i = 0; i < map->numTags; i++) { - const EventTag* tag = &map->tagArray[i]; - printf(" %3d: %6d '%s'\n", i, tag->tagIndex, tag->tagStr); - } -} - diff --git a/liblog/fake_log_device.c b/liblog/fake_log_device.c index da83a85..136792d 100644 --- a/liblog/fake_log_device.c +++ b/liblog/fake_log_device.c @@ -21,18 +21,22 @@ */ #include "fake_log_device.h" -#include <log/logd.h> - -#include <stdlib.h> -#include <string.h> #include <ctype.h> #include <errno.h> #include <fcntl.h> +#include <stdlib.h> +#include <string.h> + +#include <log/logd.h> #ifdef HAVE_PTHREADS #include <pthread.h> #endif +#ifndef __unused +#define __unused __attribute__((__unused__)) +#endif + #define kMaxTagLen 16 /* from the long-dead utils/Log.cpp */ #define kTagSetSize 16 /* arbitrary */ @@ -613,7 +617,7 @@ static int logClose(int fd) /* * Open a log output device and return a fake fd. */ -static int logOpen(const char* pathName, int flags) +static int logOpen(const char* pathName, int flags __unused) { LogState *logState; int fd = -1; diff --git a/liblog/log_read.c b/liblog/log_read.c index 47aa711..ca5a1a7 100644 --- a/liblog/log_read.c +++ b/liblog/log_read.c @@ -14,37 +14,180 @@ ** limitations under the License. */ -#define _GNU_SOURCE /* asprintf for x86 host */ #include <errno.h> #include <fcntl.h> +#include <inttypes.h> #include <poll.h> -#include <string.h> -#include <stdio.h> +#include <signal.h> +#include <stddef.h> +#define NOMINMAX /* for windows to suppress definition of min in stdlib.h */ #include <stdlib.h> +#include <string.h> +#include <sys/cdefs.h> +#include <unistd.h> + #include <cutils/list.h> +#include <cutils/sockets.h> #include <log/log.h> #include <log/logger.h> -#include <sys/ioctl.h> +/* branchless on many architectures. */ +#define min(x,y) ((y) ^ (((x) ^ (y)) & -((x) < (y)))) + +#define WEAK __attribute__((weak)) +#ifndef __unused +#define __unused __attribute__((unused)) +#endif + +/* Private copy of ../libcutils/socket_local_client.c prevent library loops */ + +#ifdef HAVE_WINSOCK + +int WEAK socket_local_client(const char *name, int namespaceId, int type) +{ + errno = ENOSYS; + return -ENOSYS; +} + +#else /* !HAVE_WINSOCK */ + +#include <sys/socket.h> +#include <sys/un.h> +#include <sys/select.h> +#include <sys/types.h> + +/* Private copy of ../libcutils/socket_local.h prevent library loops */ +#define FILESYSTEM_SOCKET_PREFIX "/tmp/" +#define ANDROID_RESERVED_SOCKET_PREFIX "/dev/socket/" +/* End of ../libcutils/socket_local.h */ + +#define LISTEN_BACKLOG 4 + +/* Documented in header file. */ +int WEAK socket_make_sockaddr_un(const char *name, int namespaceId, + struct sockaddr_un *p_addr, socklen_t *alen) +{ + memset (p_addr, 0, sizeof (*p_addr)); + size_t namelen; + + switch (namespaceId) { + case ANDROID_SOCKET_NAMESPACE_ABSTRACT: +#ifdef HAVE_LINUX_LOCAL_SOCKET_NAMESPACE + namelen = strlen(name); + + /* Test with length +1 for the *initial* '\0'. */ + if ((namelen + 1) > sizeof(p_addr->sun_path)) { + goto error; + } + + /* + * Note: The path in this case is *not* supposed to be + * '\0'-terminated. ("man 7 unix" for the gory details.) + */ + + p_addr->sun_path[0] = 0; + memcpy(p_addr->sun_path + 1, name, namelen); +#else /*HAVE_LINUX_LOCAL_SOCKET_NAMESPACE*/ + /* this OS doesn't have the Linux abstract namespace */ + + namelen = strlen(name) + strlen(FILESYSTEM_SOCKET_PREFIX); + /* unix_path_max appears to be missing on linux */ + if (namelen > sizeof(*p_addr) + - offsetof(struct sockaddr_un, sun_path) - 1) { + goto error; + } + + strcpy(p_addr->sun_path, FILESYSTEM_SOCKET_PREFIX); + strcat(p_addr->sun_path, name); +#endif /*HAVE_LINUX_LOCAL_SOCKET_NAMESPACE*/ + break; + + case ANDROID_SOCKET_NAMESPACE_RESERVED: + namelen = strlen(name) + strlen(ANDROID_RESERVED_SOCKET_PREFIX); + /* unix_path_max appears to be missing on linux */ + if (namelen > sizeof(*p_addr) + - offsetof(struct sockaddr_un, sun_path) - 1) { + goto error; + } + + strcpy(p_addr->sun_path, ANDROID_RESERVED_SOCKET_PREFIX); + strcat(p_addr->sun_path, name); + break; + + case ANDROID_SOCKET_NAMESPACE_FILESYSTEM: + namelen = strlen(name); + /* unix_path_max appears to be missing on linux */ + if (namelen > sizeof(*p_addr) + - offsetof(struct sockaddr_un, sun_path) - 1) { + goto error; + } + + strcpy(p_addr->sun_path, name); + break; + + default: + /* invalid namespace id */ + return -1; + } + + p_addr->sun_family = AF_LOCAL; + *alen = namelen + offsetof(struct sockaddr_un, sun_path) + 1; + return 0; +error: + return -1; +} + +/** + * connect to peer named "name" on fd + * returns same fd or -1 on error. + * fd is not closed on error. that's your job. + * + * Used by AndroidSocketImpl + */ +int WEAK socket_local_client_connect(int fd, const char *name, int namespaceId, + int type __unused) +{ + struct sockaddr_un addr; + socklen_t alen; + int err; + + err = socket_make_sockaddr_un(name, namespaceId, &addr, &alen); + + if (err < 0) { + goto error; + } + + if(connect(fd, (struct sockaddr *) &addr, alen) < 0) { + goto error; + } + + return fd; -#define __LOGGERIO 0xAE +error: + return -1; +} + +/** + * connect to peer named "name" + * returns fd or -1 on error + */ +int WEAK socket_local_client(const char *name, int namespaceId, int type) +{ + int s; -#define LOGGER_GET_LOG_BUF_SIZE _IO(__LOGGERIO, 1) /* size of log */ -#define LOGGER_GET_LOG_LEN _IO(__LOGGERIO, 2) /* used log len */ -#define LOGGER_GET_NEXT_ENTRY_LEN _IO(__LOGGERIO, 3) /* next entry len */ -#define LOGGER_FLUSH_LOG _IO(__LOGGERIO, 4) /* flush log */ -#define LOGGER_GET_VERSION _IO(__LOGGERIO, 5) /* abi version */ -#define LOGGER_SET_VERSION _IO(__LOGGERIO, 6) /* abi version */ + s = socket(AF_LOCAL, type, 0); + if(s < 0) return -1; -typedef char bool; -#define false (const bool)0 -#define true (const bool)1 + if ( 0 > socket_local_client_connect(s, name, namespaceId, type)) { + close(s); + return -1; + } -#define LOG_FILE_DIR "/dev/log/" + return s; +} -/* timeout in milliseconds */ -#define LOG_TIMEOUT_FLUSH 5 -#define LOG_TIMEOUT_NEVER -1 +#endif /* !HAVE_WINSOCK */ +/* End of ../libcutils/socket_local_client.c */ #define logger_for_each(logger, logger_list) \ for (logger = node_to_item((logger_list)->node.next, struct logger, node); \ @@ -56,47 +199,21 @@ static const char *LOG_NAME[LOG_ID_MAX] = { [LOG_ID_MAIN] = "main", [LOG_ID_RADIO] = "radio", [LOG_ID_EVENTS] = "events", - [LOG_ID_SYSTEM] = "system" + [LOG_ID_SYSTEM] = "system", + [LOG_ID_CRASH] = "crash", }; -const char *android_log_id_to_name(log_id_t log_id) { +const char *android_log_id_to_name(log_id_t log_id) +{ if (log_id >= LOG_ID_MAX) { log_id = LOG_ID_MAIN; } return LOG_NAME[log_id]; } -static int accessmode(int mode) +log_id_t android_name_to_log_id(const char *logName) { - if ((mode & O_ACCMODE) == O_WRONLY) { - return W_OK; - } - if ((mode & O_ACCMODE) == O_RDWR) { - return R_OK | W_OK; - } - return R_OK; -} - -/* repeated fragment */ -static int check_allocate_accessible(char **n, const char *b, int mode) -{ - *n = NULL; - - if (!b) { - return -EINVAL; - } - - asprintf(n, LOG_FILE_DIR "%s", b); - if (!*n) { - return -1; - } - - return access(*n, accessmode(mode)); -} - -log_id_t android_name_to_log_id(const char *logName) { const char *b; - char *n; int ret; if (!logName) { @@ -109,12 +226,6 @@ log_id_t android_name_to_log_id(const char *logName) { ++b; } - ret = check_allocate_accessible(&n, b, O_RDONLY); - free(n); - if (ret) { - return ret; - } - for(ret = LOG_ID_MIN; ret < LOG_ID_MAX; ++ret) { const char *l = LOG_NAME[ret]; if (l && !strcmp(b, l)) { @@ -128,27 +239,15 @@ struct logger_list { struct listnode node; int mode; unsigned int tail; + log_time start; pid_t pid; - unsigned int queued_lines; - int timeout_ms; - int error; - bool flush; - bool valid_entry; /* valiant(?) effort to deal with memory starvation */ - struct log_msg entry; -}; - -struct log_list { - struct listnode node; - struct log_msg entry; /* Truncated to event->len() + 1 to save space */ + int sock; }; struct logger { struct listnode node; struct logger_list *top; - int fd; log_id_t id; - short *revents; - struct listnode log_list; }; /* android_logger_alloc unimplemented, no use case */ @@ -159,91 +258,209 @@ static void android_logger_free(struct logger *logger) return; } - while (!list_empty(&logger->log_list)) { - struct log_list *entry = node_to_item( - list_head(&logger->log_list), struct log_list, node); - list_remove(&entry->node); - free(entry); - if (logger->top->queued_lines) { - logger->top->queued_lines--; - } - } - - if (logger->fd >= 0) { - close(logger->fd); - } - list_remove(&logger->node); free(logger); } +/* android_logger_alloc unimplemented, no use case */ + +/* method for getting the associated sublog id */ log_id_t android_logger_get_id(struct logger *logger) { return logger->id; } /* worker for sending the command to the logger */ -static int logger_ioctl(struct logger *logger, int cmd, int mode) +static ssize_t send_log_msg(struct logger *logger, + const char *msg, char *buf, size_t buf_size) { - char *n; - int f, ret; - - if (!logger || !logger->top) { - return -EFAULT; + ssize_t ret; + size_t len; + char *cp; + int errno_save = 0; + int sock = socket_local_client("logd", ANDROID_SOCKET_NAMESPACE_RESERVED, + SOCK_STREAM); + if (sock < 0) { + return sock; } - if (((mode & O_ACCMODE) == O_RDWR) - || (((mode ^ logger->top->mode) & O_ACCMODE) == 0)) { - return ioctl(logger->fd, cmd); + if (msg) { + snprintf(buf, buf_size, msg, logger ? logger->id : (unsigned) -1); } - /* We go here if android_logger_list_open got mode wrong for this ioctl */ - ret = check_allocate_accessible(&n, android_log_id_to_name(logger->id), mode); - if (ret) { - free(n); - return ret; + len = strlen(buf) + 1; + ret = TEMP_FAILURE_RETRY(write(sock, buf, len)); + if (ret <= 0) { + goto done; } - f = open(n, mode); - free(n); - if (f < 0) { - return f; + len = buf_size; + cp = buf; + while ((ret = TEMP_FAILURE_RETRY(read(sock, cp, len))) > 0) { + struct pollfd p; + + if (((size_t)ret == len) || (buf_size < PAGE_SIZE)) { + break; + } + + len -= ret; + cp += ret; + + memset(&p, 0, sizeof(p)); + p.fd = sock; + p.events = POLLIN; + + /* Give other side 20ms to refill pipe */ + ret = TEMP_FAILURE_RETRY(poll(&p, 1, 20)); + + if (ret <= 0) { + break; + } + + if (!(p.revents & POLLIN)) { + ret = 0; + break; + } } - ret = ioctl(f, cmd); - close (f); + if (ret >= 0) { + ret += buf_size - len; + } +done: + if ((ret == -1) && errno) { + errno_save = errno; + } + close(sock); + if (errno_save) { + errno = errno_save; + } return ret; } +static int check_log_success(char *buf, ssize_t ret) +{ + if (ret < 0) { + return ret; + } + + if (strncmp(buf, "success", 7)) { + errno = EINVAL; + return -1; + } + + return 0; +} + int android_logger_clear(struct logger *logger) { - return logger_ioctl(logger, LOGGER_FLUSH_LOG, O_WRONLY); + char buf[512]; + + return check_log_success(buf, + send_log_msg(logger, "clear %d", buf, sizeof(buf))); } /* returns the total size of the log's ring buffer */ -int android_logger_get_log_size(struct logger *logger) +long android_logger_get_log_size(struct logger *logger) +{ + char buf[512]; + + ssize_t ret = send_log_msg(logger, "getLogSize %d", buf, sizeof(buf)); + if (ret < 0) { + return ret; + } + + if ((buf[0] < '0') || ('9' < buf[0])) { + return -1; + } + + return atol(buf); +} + +int android_logger_set_log_size(struct logger *logger, unsigned long size) { - return logger_ioctl(logger, LOGGER_GET_LOG_BUF_SIZE, O_RDWR); + char buf[512]; + + snprintf(buf, sizeof(buf), "setLogSize %d %lu", + logger ? logger->id : (unsigned) -1, size); + + return check_log_success(buf, send_log_msg(NULL, NULL, buf, sizeof(buf))); } /* * returns the readable size of the log's ring buffer (that is, amount of the * log consumed) */ -int android_logger_get_log_readable_size(struct logger *logger) +long android_logger_get_log_readable_size(struct logger *logger) { - return logger_ioctl(logger, LOGGER_GET_LOG_LEN, O_RDONLY); + char buf[512]; + + ssize_t ret = send_log_msg(logger, "getLogSizeUsed %d", buf, sizeof(buf)); + if (ret < 0) { + return ret; + } + + if ((buf[0] < '0') || ('9' < buf[0])) { + return -1; + } + + return atol(buf); } /* * returns the logger version */ -int android_logger_get_log_version(struct logger *logger) +int android_logger_get_log_version(struct logger *logger __unused) +{ + return 3; +} + +/* + * returns statistics + */ +ssize_t android_logger_get_statistics(struct logger_list *logger_list, + char *buf, size_t len) +{ + struct logger *logger; + char *cp = buf; + size_t remaining = len; + size_t n; + + n = snprintf(cp, remaining, "getStatistics"); + n = min(n, remaining); + remaining -= n; + cp += n; + + logger_for_each(logger, logger_list) { + n = snprintf(cp, remaining, " %d", logger->id); + n = min(n, remaining); + remaining -= n; + cp += n; + } + return send_log_msg(NULL, NULL, buf, len); +} + +ssize_t android_logger_get_prune_list(struct logger_list *logger_list __unused, + char *buf, size_t len) +{ + return send_log_msg(NULL, "getPruneList", buf, len); +} + +int android_logger_set_prune_list(struct logger_list *logger_list __unused, + char *buf, size_t len) { - int ret = logger_ioctl(logger, LOGGER_GET_VERSION, O_RDWR); - return (ret < 0) ? 1 : ret; + const char cmd[] = "setPruneList "; + const size_t cmdlen = sizeof(cmd) - 1; + + if (strlen(buf) > (len - cmdlen)) { + return -ENOMEM; /* KISS */ + } + memmove(buf + cmdlen, buf, len - cmdlen); + buf[len - 1] = '\0'; + memcpy(buf, cmd, cmdlen); + + return check_log_success(buf, send_log_msg(NULL, NULL, buf, len)); } struct logger_list *android_logger_list_alloc(int mode, @@ -256,10 +473,36 @@ struct logger_list *android_logger_list_alloc(int mode, if (!logger_list) { return NULL; } + list_init(&logger_list->node); logger_list->mode = mode; + logger_list->start.tv_sec = 0; + logger_list->start.tv_nsec = 0; logger_list->tail = tail; logger_list->pid = pid; + logger_list->sock = -1; + + return logger_list; +} + +struct logger_list *android_logger_list_alloc_time(int mode, + log_time start, + pid_t pid) +{ + struct logger_list *logger_list; + + logger_list = calloc(1, sizeof(*logger_list)); + if (!logger_list) { + return NULL; + } + + list_init(&logger_list->node); + logger_list->mode = mode; + logger_list->start = start; + logger_list->tail = 0; + logger_list->pid = pid; + logger_list->sock = -1; + return logger_list; } @@ -270,9 +513,7 @@ struct logger_list *android_logger_list_alloc(int mode, struct logger *android_logger_open(struct logger_list *logger_list, log_id_t id) { - struct listnode *node; struct logger *logger; - char *n; if (!logger_list || (id >= LOG_ID_MAX)) { goto err; @@ -289,28 +530,11 @@ struct logger *android_logger_open(struct logger_list *logger_list, goto err; } - if (check_allocate_accessible(&n, android_log_id_to_name(id), - logger_list->mode)) { - goto err_name; - } - - logger->fd = open(n, logger_list->mode); - if (logger->fd < 0) { - goto err_name; - } - - free(n); logger->id = id; - list_init(&logger->log_list); list_add_tail(&logger_list->node, &logger->node); logger->top = logger_list; - logger_list->timeout_ms = LOG_TIMEOUT_FLUSH; goto ok; -err_name: - free(n); -err_logger: - free(logger); err: logger = NULL; ok: @@ -336,315 +560,146 @@ struct logger_list *android_logger_list_open(log_id_t id, return logger_list; } -/* prevent memory starvation when backfilling */ -static unsigned int queue_threshold(struct logger_list *logger_list) -{ - return (logger_list->tail < 64) ? 64 : logger_list->tail; -} - -static bool low_queue(struct listnode *node) -{ - /* low is considered less than 2 */ - return list_head(node) == list_tail(node); -} - -/* Flush queues in sequential order, one at a time */ -static int android_logger_list_flush(struct logger_list *logger_list, - struct log_msg *log_msg) +static void caught_signal(int signum __unused) { - int ret = 0; - struct log_list *firstentry = NULL; - - while ((ret == 0) - && (logger_list->flush - || (logger_list->queued_lines > logger_list->tail))) { - struct logger *logger; - - /* Merge sort */ - bool at_least_one_is_low = false; - struct logger *firstlogger = NULL; - firstentry = NULL; - - logger_for_each(logger, logger_list) { - struct listnode *node; - struct log_list *oldest = NULL; - - /* kernel logger channels not necessarily time-sort order */ - list_for_each(node, &logger->log_list) { - struct log_list *entry = node_to_item(node, - struct log_list, node); - if (!oldest - || (entry->entry.entry.sec < oldest->entry.entry.sec) - || ((entry->entry.entry.sec == oldest->entry.entry.sec) - && (entry->entry.entry.nsec < oldest->entry.entry.nsec))) { - oldest = entry; - } - } - - if (!oldest) { - at_least_one_is_low = true; - continue; - } else if (low_queue(&logger->log_list)) { - at_least_one_is_low = true; - } - - if (!firstentry - || (oldest->entry.entry.sec < firstentry->entry.entry.sec) - || ((oldest->entry.entry.sec == firstentry->entry.entry.sec) - && (oldest->entry.entry.nsec < firstentry->entry.entry.nsec))) { - firstentry = oldest; - firstlogger = logger; - } - } - - if (!firstentry) { - break; - } - - /* when trimming list, tries to keep one entry behind in each bucket */ - if (!logger_list->flush - && at_least_one_is_low - && (logger_list->queued_lines < queue_threshold(logger_list))) { - break; - } - - /* within tail?, send! */ - if ((logger_list->tail == 0) - || (logger_list->queued_lines <= logger_list->tail)) { - ret = firstentry->entry.entry.hdr_size; - if (!ret) { - ret = sizeof(firstentry->entry.entry_v1); - } - ret += firstentry->entry.entry.len; - - memcpy(log_msg->buf, firstentry->entry.buf, ret + 1); - log_msg->extra.id = firstlogger->id; - } - - /* next entry */ - list_remove(&firstentry->node); - free(firstentry); - if (logger_list->queued_lines) { - logger_list->queued_lines--; - } - } - - /* Flushed the list, no longer in tail mode for continuing content */ - if (logger_list->flush && !firstentry) { - logger_list->tail = 0; - } - return ret; } /* Read from the selected logs */ int android_logger_list_read(struct logger_list *logger_list, struct log_msg *log_msg) { + int ret, e; struct logger *logger; - nfds_t nfds; - struct pollfd *p, *pollfds = NULL; - int error = 0, ret = 0; - - memset(log_msg, 0, sizeof(struct log_msg)); + struct sigaction ignore; + struct sigaction old_sigaction; + unsigned int old_alarm = 0; if (!logger_list) { - return -ENODEV; - } - - if (!(accessmode(logger_list->mode) & R_OK)) { - logger_list->error = EPERM; - goto done; - } - - nfds = 0; - logger_for_each(logger, logger_list) { - ++nfds; - } - if (nfds <= 0) { - error = ENODEV; - goto done; - } - - /* Do we have anything to offer from the buffer or state? */ - if (logger_list->valid_entry) { /* implies we are also in a flush state */ - goto flush; - } - - ret = android_logger_list_flush(logger_list, log_msg); - if (ret) { - goto done; + return -EINVAL; } - if (logger_list->error) { /* implies we are also in a flush state */ - goto done; + if (logger_list->mode & O_NONBLOCK) { + memset(&ignore, 0, sizeof(ignore)); + ignore.sa_handler = caught_signal; + sigemptyset(&ignore.sa_mask); } - /* Lets start grinding on metal */ - pollfds = calloc(nfds, sizeof(struct pollfd)); - if (!pollfds) { - error = ENOMEM; - goto flush; - } + if (logger_list->sock < 0) { + char buffer[256], *cp, c; - p = pollfds; - logger_for_each(logger, logger_list) { - p->fd = logger->fd; - p->events = POLLIN; - logger->revents = &p->revents; - ++p; - } - - while (!ret && !error) { - int result; - - /* If we oversleep it's ok, i.e. ignore EINTR. */ - result = TEMP_FAILURE_RETRY( - poll(pollfds, nfds, logger_list->timeout_ms)); - - if (result <= 0) { - if (result) { - error = errno; - } else if (logger_list->mode & O_NDELAY) { - error = EAGAIN; - } else { - logger_list->timeout_ms = LOG_TIMEOUT_NEVER; + int sock = socket_local_client("logdr", + ANDROID_SOCKET_NAMESPACE_RESERVED, + SOCK_SEQPACKET); + if (sock < 0) { + if ((sock == -1) && errno) { + return -errno; } - - logger_list->flush = true; - goto try_flush; + return sock; } - logger_list->timeout_ms = LOG_TIMEOUT_FLUSH; - - /* Anti starvation */ - if (!logger_list->flush - && (logger_list->queued_lines > (queue_threshold(logger_list) / 2))) { - /* Any queues with input pending that is low? */ - bool starving = false; - logger_for_each(logger, logger_list) { - if ((*(logger->revents) & POLLIN) - && low_queue(&logger->log_list)) { - starving = true; - break; - } - } + strcpy(buffer, + (logger_list->mode & O_NONBLOCK) ? "dumpAndClose" : "stream"); + cp = buffer + strlen(buffer); - /* pushback on any queues that are not low */ - if (starving) { - logger_for_each(logger, logger_list) { - if ((*(logger->revents) & POLLIN) - && !low_queue(&logger->log_list)) { - *(logger->revents) &= ~POLLIN; - } - } - } + strcpy(cp, " lids"); + cp += 5; + c = '='; + int remaining = sizeof(buffer) - (cp - buffer); + logger_for_each(logger, logger_list) { + ret = snprintf(cp, remaining, "%c%u", c, logger->id); + ret = min(ret, remaining); + remaining -= ret; + cp += ret; + c = ','; } - logger_for_each(logger, logger_list) { - unsigned int hdr_size; - struct log_list *entry; + if (logger_list->tail) { + ret = snprintf(cp, remaining, " tail=%u", logger_list->tail); + ret = min(ret, remaining); + remaining -= ret; + cp += ret; + } - if (!(*(logger->revents) & POLLIN)) { - continue; - } + if (logger_list->start.tv_sec || logger_list->start.tv_nsec) { + ret = snprintf(cp, remaining, " start=%" PRIu32 ".%09" PRIu32, + logger_list->start.tv_sec, + logger_list->start.tv_nsec); + ret = min(ret, remaining); + remaining -= ret; + cp += ret; + } - memset(logger_list->entry.buf, 0, sizeof(struct log_msg)); - /* NOTE: driver guarantees we read exactly one full entry */ - result = read(logger->fd, logger_list->entry.buf, - LOGGER_ENTRY_MAX_LEN); - if (result <= 0) { - if (!result) { - error = EIO; - } else if (errno != EINTR) { - error = errno; - } - continue; - } + if (logger_list->pid) { + ret = snprintf(cp, remaining, " pid=%u", logger_list->pid); + ret = min(ret, remaining); + remaining -= ret; + cp += ret; + } - if (logger_list->pid - && (logger_list->pid != logger_list->entry.entry.pid)) { - continue; + if (logger_list->mode & O_NONBLOCK) { + /* Deal with an unresponsive logd */ + sigaction(SIGALRM, &ignore, &old_sigaction); + old_alarm = alarm(30); + } + ret = write(sock, buffer, cp - buffer); + e = errno; + if (logger_list->mode & O_NONBLOCK) { + if (e == EINTR) { + e = ETIMEDOUT; } + alarm(old_alarm); + sigaction(SIGALRM, &old_sigaction, NULL); + } - hdr_size = logger_list->entry.entry.hdr_size; - if (!hdr_size) { - hdr_size = sizeof(logger_list->entry.entry_v1); + if (ret <= 0) { + close(sock); + if ((ret == -1) && e) { + return -e; } - - if ((hdr_size > sizeof(struct log_msg)) - || (logger_list->entry.entry.len - > sizeof(logger_list->entry.buf) - hdr_size) - || (logger_list->entry.entry.len != result - hdr_size)) { - error = EINVAL; - continue; + if (ret == 0) { + return -EIO; } + return ret; + } - logger_list->entry.extra.id = logger->id; - - /* speedup: If not tail, and only one list, send directly */ - if (!logger_list->tail - && (list_head(&logger_list->node) - == list_tail(&logger_list->node))) { - ret = result; - memcpy(log_msg->buf, logger_list->entry.buf, result + 1); - log_msg->extra.id = logger->id; - break; - } + logger_list->sock = sock; + } - entry = malloc(sizeof(*entry) - sizeof(entry->entry) + result + 1); + ret = 0; + while(1) { + memset(log_msg, 0, sizeof(*log_msg)); - if (!entry) { - logger_list->valid_entry = true; - error = ENOMEM; - break; + if (logger_list->mode & O_NONBLOCK) { + /* particularily useful if tombstone is reporting for logd */ + sigaction(SIGALRM, &ignore, &old_sigaction); + old_alarm = alarm(30); + } + /* NOTE: SOCK_SEQPACKET guarantees we read exactly one full entry */ + ret = recv(logger_list->sock, log_msg, LOGGER_ENTRY_MAX_LEN, 0); + e = errno; + if (logger_list->mode & O_NONBLOCK) { + if ((ret == 0) || (e == EINTR)) { + e = EAGAIN; + ret = -1; } - - logger_list->queued_lines++; - - memcpy(entry->entry.buf, logger_list->entry.buf, result); - entry->entry.buf[result] = '\0'; - list_add_tail(&logger->log_list, &entry->node); + alarm(old_alarm); + sigaction(SIGALRM, &old_sigaction, NULL); } if (ret <= 0) { -try_flush: - ret = android_logger_list_flush(logger_list, log_msg); - } - } - - free(pollfds); - -flush: - if (error) { - logger_list->flush = true; - } - - if (ret <= 0) { - ret = android_logger_list_flush(logger_list, log_msg); - - if (!ret && logger_list->valid_entry) { - ret = logger_list->entry.entry.hdr_size; - if (!ret) { - ret = sizeof(logger_list->entry.entry_v1); + if ((ret == -1) && e) { + return -e; } - ret += logger_list->entry.entry.len; - - memcpy(log_msg->buf, logger_list->entry.buf, - sizeof(struct log_msg)); - logger_list->valid_entry = false; + return ret; } - } -done: - if (logger_list->error) { - error = logger_list->error; - } - if (error) { - logger_list->error = error; - if (!ret) { - ret = -error; + logger_for_each(logger, logger_list) { + if (log_msg->entry.lid == logger->id) { + return ret; + } } } + /* NOTREACH */ return ret; } @@ -661,5 +716,9 @@ void android_logger_list_free(struct logger_list *logger_list) android_logger_free(logger); } + if (logger_list->sock >= 0) { + close (logger_list->sock); + } + free(logger_list); } diff --git a/liblog/log_read_kern.c b/liblog/log_read_kern.c new file mode 100644 index 0000000..41b8a51 --- /dev/null +++ b/liblog/log_read_kern.c @@ -0,0 +1,741 @@ +/* +** Copyright 2013-2014, The Android Open Source Project +** +** Licensed under the Apache License, Version 2.0 (the "License"); +** you may not use this file except in compliance with the License. +** You may obtain a copy of the License at +** +** http://www.apache.org/licenses/LICENSE-2.0 +** +** Unless required by applicable law or agreed to in writing, software +** distributed under the License is distributed on an "AS IS" BASIS, +** WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +** See the License for the specific language governing permissions and +** limitations under the License. +*/ + +#define _GNU_SOURCE /* asprintf for x86 host */ +#include <errno.h> +#include <fcntl.h> +#include <poll.h> +#include <string.h> +#include <stdio.h> +#include <stdlib.h> +#include <sys/cdefs.h> +#include <sys/ioctl.h> + +#include <cutils/list.h> +#include <log/log.h> +#include <log/logger.h> + +#define __LOGGERIO 0xAE + +#define LOGGER_GET_LOG_BUF_SIZE _IO(__LOGGERIO, 1) /* size of log */ +#define LOGGER_GET_LOG_LEN _IO(__LOGGERIO, 2) /* used log len */ +#define LOGGER_GET_NEXT_ENTRY_LEN _IO(__LOGGERIO, 3) /* next entry len */ +#define LOGGER_FLUSH_LOG _IO(__LOGGERIO, 4) /* flush log */ +#define LOGGER_GET_VERSION _IO(__LOGGERIO, 5) /* abi version */ +#define LOGGER_SET_VERSION _IO(__LOGGERIO, 6) /* abi version */ + +typedef char bool; +#define false (const bool)0 +#define true (const bool)1 + +#define LOG_FILE_DIR "/dev/log/" + +/* timeout in milliseconds */ +#define LOG_TIMEOUT_FLUSH 5 +#define LOG_TIMEOUT_NEVER -1 + +#define logger_for_each(logger, logger_list) \ + for (logger = node_to_item((logger_list)->node.next, struct logger, node); \ + logger != node_to_item(&(logger_list)->node, struct logger, node); \ + logger = node_to_item((logger)->node.next, struct logger, node)) + +#ifndef __unused +#define __unused __attribute__((unused)) +#endif + +/* In the future, we would like to make this list extensible */ +static const char *LOG_NAME[LOG_ID_MAX] = { + [LOG_ID_MAIN] = "main", + [LOG_ID_RADIO] = "radio", + [LOG_ID_EVENTS] = "events", + [LOG_ID_SYSTEM] = "system", + [LOG_ID_CRASH] = "crash" +}; + +const char *android_log_id_to_name(log_id_t log_id) +{ + if (log_id >= LOG_ID_MAX) { + log_id = LOG_ID_MAIN; + } + return LOG_NAME[log_id]; +} + +static int accessmode(int mode) +{ + if ((mode & O_ACCMODE) == O_WRONLY) { + return W_OK; + } + if ((mode & O_ACCMODE) == O_RDWR) { + return R_OK | W_OK; + } + return R_OK; +} + +/* repeated fragment */ +static int check_allocate_accessible(char **n, const char *b, int mode) +{ + *n = NULL; + + if (!b) { + return -EINVAL; + } + + asprintf(n, LOG_FILE_DIR "%s", b); + if (!*n) { + return -1; + } + + return access(*n, accessmode(mode)); +} + +log_id_t android_name_to_log_id(const char *logName) +{ + const char *b; + char *n; + int ret; + + if (!logName) { + return -1; /* NB: log_id_t is unsigned */ + } + b = strrchr(logName, '/'); + if (!b) { + b = logName; + } else { + ++b; + } + + ret = check_allocate_accessible(&n, b, O_RDONLY); + free(n); + if (ret) { + return ret; + } + + for(ret = LOG_ID_MIN; ret < LOG_ID_MAX; ++ret) { + const char *l = LOG_NAME[ret]; + if (l && !strcmp(b, l)) { + return ret; + } + } + return -1; /* should never happen */ +} + +struct logger_list { + struct listnode node; + int mode; + unsigned int tail; + pid_t pid; + unsigned int queued_lines; + int timeout_ms; + int error; + bool flush; + bool valid_entry; /* valiant(?) effort to deal with memory starvation */ + struct log_msg entry; +}; + +struct log_list { + struct listnode node; + struct log_msg entry; /* Truncated to event->len() + 1 to save space */ +}; + +struct logger { + struct listnode node; + struct logger_list *top; + int fd; + log_id_t id; + short *revents; + struct listnode log_list; +}; + +/* android_logger_alloc unimplemented, no use case */ +/* android_logger_free not exported */ +static void android_logger_free(struct logger *logger) +{ + if (!logger) { + return; + } + + while (!list_empty(&logger->log_list)) { + struct log_list *entry = node_to_item( + list_head(&logger->log_list), struct log_list, node); + list_remove(&entry->node); + free(entry); + if (logger->top->queued_lines) { + logger->top->queued_lines--; + } + } + + if (logger->fd >= 0) { + close(logger->fd); + } + + list_remove(&logger->node); + + free(logger); +} + +log_id_t android_logger_get_id(struct logger *logger) +{ + return logger->id; +} + +/* worker for sending the command to the logger */ +static int logger_ioctl(struct logger *logger, int cmd, int mode) +{ + char *n; + int f, ret; + + if (!logger || !logger->top) { + return -EFAULT; + } + + if (((mode & O_ACCMODE) == O_RDWR) + || (((mode ^ logger->top->mode) & O_ACCMODE) == 0)) { + return ioctl(logger->fd, cmd); + } + + /* We go here if android_logger_list_open got mode wrong for this ioctl */ + ret = check_allocate_accessible(&n, android_log_id_to_name(logger->id), mode); + if (ret) { + free(n); + return ret; + } + + f = open(n, mode); + free(n); + if (f < 0) { + return f; + } + + ret = ioctl(f, cmd); + close (f); + + return ret; +} + +int android_logger_clear(struct logger *logger) +{ + return logger_ioctl(logger, LOGGER_FLUSH_LOG, O_WRONLY); +} + +/* returns the total size of the log's ring buffer */ +long android_logger_get_log_size(struct logger *logger) +{ + return logger_ioctl(logger, LOGGER_GET_LOG_BUF_SIZE, O_RDWR); +} + +int android_logger_set_log_size(struct logger *logger __unused, + unsigned long size __unused) +{ + return -ENOTSUP; +} + +/* + * returns the readable size of the log's ring buffer (that is, amount of the + * log consumed) + */ +long android_logger_get_log_readable_size(struct logger *logger) +{ + return logger_ioctl(logger, LOGGER_GET_LOG_LEN, O_RDONLY); +} + +/* + * returns the logger version + */ +int android_logger_get_log_version(struct logger *logger) +{ + int ret = logger_ioctl(logger, LOGGER_GET_VERSION, O_RDWR); + return (ret < 0) ? 1 : ret; +} + +/* + * returns statistics + */ +static const char unsupported[] = "18\nNot Supported\n\f"; + +ssize_t android_logger_get_statistics(struct logger_list *logger_list __unused, + char *buf, size_t len) +{ + strncpy(buf, unsupported, len); + return -ENOTSUP; +} + +ssize_t android_logger_get_prune_list(struct logger_list *logger_list __unused, + char *buf, size_t len) +{ + strncpy(buf, unsupported, len); + return -ENOTSUP; +} + +int android_logger_set_prune_list(struct logger_list *logger_list __unused, + char *buf, size_t len) +{ + static const char unsupported_error[] = "Unsupported"; + strncpy(buf, unsupported, len); + return -ENOTSUP; +} + +struct logger_list *android_logger_list_alloc(int mode, + unsigned int tail, + pid_t pid) +{ + struct logger_list *logger_list; + + logger_list = calloc(1, sizeof(*logger_list)); + if (!logger_list) { + return NULL; + } + list_init(&logger_list->node); + logger_list->mode = mode; + logger_list->tail = tail; + logger_list->pid = pid; + return logger_list; +} + +struct logger_list *android_logger_list_alloc_time(int mode, + log_time start __unused, + pid_t pid) +{ + return android_logger_list_alloc(mode, 0, pid); +} + +/* android_logger_list_register unimplemented, no use case */ +/* android_logger_list_unregister unimplemented, no use case */ + +/* Open the named log and add it to the logger list */ +struct logger *android_logger_open(struct logger_list *logger_list, + log_id_t id) +{ + struct listnode *node; + struct logger *logger; + char *n; + + if (!logger_list || (id >= LOG_ID_MAX)) { + goto err; + } + + logger_for_each(logger, logger_list) { + if (logger->id == id) { + goto ok; + } + } + + logger = calloc(1, sizeof(*logger)); + if (!logger) { + goto err; + } + + if (check_allocate_accessible(&n, android_log_id_to_name(id), + logger_list->mode)) { + goto err_name; + } + + logger->fd = open(n, logger_list->mode); + if (logger->fd < 0) { + goto err_name; + } + + free(n); + logger->id = id; + list_init(&logger->log_list); + list_add_tail(&logger_list->node, &logger->node); + logger->top = logger_list; + logger_list->timeout_ms = LOG_TIMEOUT_FLUSH; + goto ok; + +err_name: + free(n); +err_logger: + free(logger); +err: + logger = NULL; +ok: + return logger; +} + +/* Open the single named log and make it part of a new logger list */ +struct logger_list *android_logger_list_open(log_id_t id, + int mode, + unsigned int tail, + pid_t pid) +{ + struct logger_list *logger_list = android_logger_list_alloc(mode, tail, pid); + if (!logger_list) { + return NULL; + } + + if (!android_logger_open(logger_list, id)) { + android_logger_list_free(logger_list); + return NULL; + } + + return logger_list; +} + +/* prevent memory starvation when backfilling */ +static unsigned int queue_threshold(struct logger_list *logger_list) +{ + return (logger_list->tail < 64) ? 64 : logger_list->tail; +} + +static bool low_queue(struct listnode *node) +{ + /* low is considered less than 2 */ + return list_head(node) == list_tail(node); +} + +/* Flush queues in sequential order, one at a time */ +static int android_logger_list_flush(struct logger_list *logger_list, + struct log_msg *log_msg) +{ + int ret = 0; + struct log_list *firstentry = NULL; + + while ((ret == 0) + && (logger_list->flush + || (logger_list->queued_lines > logger_list->tail))) { + struct logger *logger; + + /* Merge sort */ + bool at_least_one_is_low = false; + struct logger *firstlogger = NULL; + firstentry = NULL; + + logger_for_each(logger, logger_list) { + struct listnode *node; + struct log_list *oldest = NULL; + + /* kernel logger channels not necessarily time-sort order */ + list_for_each(node, &logger->log_list) { + struct log_list *entry = node_to_item(node, + struct log_list, node); + if (!oldest + || (entry->entry.entry.sec < oldest->entry.entry.sec) + || ((entry->entry.entry.sec == oldest->entry.entry.sec) + && (entry->entry.entry.nsec < oldest->entry.entry.nsec))) { + oldest = entry; + } + } + + if (!oldest) { + at_least_one_is_low = true; + continue; + } else if (low_queue(&logger->log_list)) { + at_least_one_is_low = true; + } + + if (!firstentry + || (oldest->entry.entry.sec < firstentry->entry.entry.sec) + || ((oldest->entry.entry.sec == firstentry->entry.entry.sec) + && (oldest->entry.entry.nsec < firstentry->entry.entry.nsec))) { + firstentry = oldest; + firstlogger = logger; + } + } + + if (!firstentry) { + break; + } + + /* when trimming list, tries to keep one entry behind in each bucket */ + if (!logger_list->flush + && at_least_one_is_low + && (logger_list->queued_lines < queue_threshold(logger_list))) { + break; + } + + /* within tail?, send! */ + if ((logger_list->tail == 0) + || (logger_list->queued_lines <= logger_list->tail)) { + int diff; + ret = firstentry->entry.entry.hdr_size; + if (!ret) { + ret = sizeof(firstentry->entry.entry_v1); + } + + /* Promote entry to v3 format */ + memcpy(log_msg->buf, firstentry->entry.buf, ret); + diff = sizeof(firstentry->entry.entry_v3) - ret; + if (diff < 0) { + diff = 0; + } else if (diff > 0) { + memset(log_msg->buf + ret, 0, diff); + } + memcpy(log_msg->buf + ret + diff, firstentry->entry.buf + ret, + firstentry->entry.entry.len + 1); + ret += diff; + log_msg->entry.hdr_size = ret; + log_msg->entry.lid = firstlogger->id; + + ret += firstentry->entry.entry.len; + } + + /* next entry */ + list_remove(&firstentry->node); + free(firstentry); + if (logger_list->queued_lines) { + logger_list->queued_lines--; + } + } + + /* Flushed the list, no longer in tail mode for continuing content */ + if (logger_list->flush && !firstentry) { + logger_list->tail = 0; + } + return ret; +} + +/* Read from the selected logs */ +int android_logger_list_read(struct logger_list *logger_list, + struct log_msg *log_msg) +{ + struct logger *logger; + nfds_t nfds; + struct pollfd *p, *pollfds = NULL; + int error = 0, ret = 0; + + memset(log_msg, 0, sizeof(struct log_msg)); + + if (!logger_list) { + return -ENODEV; + } + + if (!(accessmode(logger_list->mode) & R_OK)) { + logger_list->error = EPERM; + goto done; + } + + nfds = 0; + logger_for_each(logger, logger_list) { + ++nfds; + } + if (nfds <= 0) { + error = ENODEV; + goto done; + } + + /* Do we have anything to offer from the buffer or state? */ + if (logger_list->valid_entry) { /* implies we are also in a flush state */ + goto flush; + } + + ret = android_logger_list_flush(logger_list, log_msg); + if (ret) { + goto done; + } + + if (logger_list->error) { /* implies we are also in a flush state */ + goto done; + } + + /* Lets start grinding on metal */ + pollfds = calloc(nfds, sizeof(struct pollfd)); + if (!pollfds) { + error = ENOMEM; + goto flush; + } + + p = pollfds; + logger_for_each(logger, logger_list) { + p->fd = logger->fd; + p->events = POLLIN; + logger->revents = &p->revents; + ++p; + } + + while (!ret && !error) { + int result; + + /* If we oversleep it's ok, i.e. ignore EINTR. */ + result = TEMP_FAILURE_RETRY( + poll(pollfds, nfds, logger_list->timeout_ms)); + + if (result <= 0) { + if (result) { + error = errno; + } else if (logger_list->mode & O_NDELAY) { + error = EAGAIN; + } else { + logger_list->timeout_ms = LOG_TIMEOUT_NEVER; + } + + logger_list->flush = true; + goto try_flush; + } + + logger_list->timeout_ms = LOG_TIMEOUT_FLUSH; + + /* Anti starvation */ + if (!logger_list->flush + && (logger_list->queued_lines > (queue_threshold(logger_list) / 2))) { + /* Any queues with input pending that is low? */ + bool starving = false; + logger_for_each(logger, logger_list) { + if ((*(logger->revents) & POLLIN) + && low_queue(&logger->log_list)) { + starving = true; + break; + } + } + + /* pushback on any queues that are not low */ + if (starving) { + logger_for_each(logger, logger_list) { + if ((*(logger->revents) & POLLIN) + && !low_queue(&logger->log_list)) { + *(logger->revents) &= ~POLLIN; + } + } + } + } + + logger_for_each(logger, logger_list) { + unsigned int hdr_size; + struct log_list *entry; + int diff; + + if (!(*(logger->revents) & POLLIN)) { + continue; + } + + memset(logger_list->entry.buf, 0, sizeof(struct log_msg)); + /* NOTE: driver guarantees we read exactly one full entry */ + result = read(logger->fd, logger_list->entry.buf, + LOGGER_ENTRY_MAX_LEN); + if (result <= 0) { + if (!result) { + error = EIO; + } else if (errno != EINTR) { + error = errno; + } + continue; + } + + if (logger_list->pid + && (logger_list->pid != logger_list->entry.entry.pid)) { + continue; + } + + hdr_size = logger_list->entry.entry.hdr_size; + if (!hdr_size) { + hdr_size = sizeof(logger_list->entry.entry_v1); + } + + if ((hdr_size > sizeof(struct log_msg)) + || (logger_list->entry.entry.len + > sizeof(logger_list->entry.buf) - hdr_size) + || (logger_list->entry.entry.len != result - hdr_size)) { + error = EINVAL; + continue; + } + + /* Promote entry to v3 format */ + diff = sizeof(logger_list->entry.entry_v3) - hdr_size; + if (diff > 0) { + if (logger_list->entry.entry.len + > sizeof(logger_list->entry.buf) - hdr_size - diff) { + error = EINVAL; + continue; + } + result += diff; + memmove(logger_list->entry.buf + hdr_size + diff, + logger_list->entry.buf + hdr_size, + logger_list->entry.entry.len + 1); + memset(logger_list->entry.buf + hdr_size, 0, diff); + logger_list->entry.entry.hdr_size = hdr_size + diff; + } + logger_list->entry.entry.lid = logger->id; + + /* speedup: If not tail, and only one list, send directly */ + if (!logger_list->tail + && (list_head(&logger_list->node) + == list_tail(&logger_list->node))) { + ret = result; + memcpy(log_msg->buf, logger_list->entry.buf, result + 1); + break; + } + + entry = malloc(sizeof(*entry) - sizeof(entry->entry) + result + 1); + + if (!entry) { + logger_list->valid_entry = true; + error = ENOMEM; + break; + } + + logger_list->queued_lines++; + + memcpy(entry->entry.buf, logger_list->entry.buf, result); + entry->entry.buf[result] = '\0'; + list_add_tail(&logger->log_list, &entry->node); + } + + if (ret <= 0) { +try_flush: + ret = android_logger_list_flush(logger_list, log_msg); + } + } + + free(pollfds); + +flush: + if (error) { + logger_list->flush = true; + } + + if (ret <= 0) { + ret = android_logger_list_flush(logger_list, log_msg); + + if (!ret && logger_list->valid_entry) { + ret = logger_list->entry.entry.hdr_size; + if (!ret) { + ret = sizeof(logger_list->entry.entry_v1); + } + ret += logger_list->entry.entry.len; + + memcpy(log_msg->buf, logger_list->entry.buf, + sizeof(struct log_msg)); + logger_list->valid_entry = false; + } + } + +done: + if (logger_list->error) { + error = logger_list->error; + } + if (error) { + logger_list->error = error; + if (!ret) { + ret = -error; + } + } + return ret; +} + +/* Close all the logs */ +void android_logger_list_free(struct logger_list *logger_list) +{ + if (logger_list == NULL) { + return; + } + + while (!list_empty(&logger_list->node)) { + struct listnode *node = list_head(&logger_list->node); + struct logger *logger = node_to_item(node, struct logger, node); + android_logger_free(logger); + } + + free(logger_list); +} diff --git a/liblog/log_time.cpp b/liblog/log_time.cpp new file mode 100644 index 0000000..755c2d9 --- /dev/null +++ b/liblog/log_time.cpp @@ -0,0 +1,168 @@ +/* + * Copyright (C) 2014 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include <ctype.h> +#include <limits.h> +#include <stdio.h> +#include <string.h> +#include <sys/cdefs.h> + +#include <log/log_read.h> + +const char log_time::default_format[] = "%m-%d %H:%M:%S.%3q"; +const timespec log_time::EPOCH = { 0, 0 }; + +// Add %#q for fractional seconds to standard strptime function + +char *log_time::strptime(const char *s, const char *format) { + time_t now; +#ifdef __linux__ + *this = log_time(CLOCK_REALTIME); + now = tv_sec; +#else + time(&now); + tv_sec = now; + tv_nsec = 0; +#endif + + struct tm *ptm; +#if (defined(HAVE_LOCALTIME_R)) + struct tm tmBuf; + ptm = localtime_r(&now, &tmBuf); +#else + ptm = localtime(&now); +#endif + + char fmt[strlen(format) + 1]; + strcpy(fmt, format); + + char *ret = const_cast<char *> (s); + char *cp; + for (char *f = cp = fmt; ; ++cp) { + if (!*cp) { + if (f != cp) { + ret = ::strptime(ret, f, ptm); + } + break; + } + if (*cp != '%') { + continue; + } + char *e = cp; + ++e; +#if (defined(__BIONIC__)) + if (*e == 's') { + *cp = '\0'; + if (*f) { + ret = ::strptime(ret, f, ptm); + if (!ret) { + break; + } + } + tv_sec = 0; + while (isdigit(*ret)) { + tv_sec = tv_sec * 10 + *ret - '0'; + ++ret; + } + now = tv_sec; +#if (defined(HAVE_LOCALTIME_R)) + ptm = localtime_r(&now, &tmBuf); +#else + ptm = localtime(&now); +#endif + } else +#endif + { + unsigned num = 0; + while (isdigit(*e)) { + num = num * 10 + *e - '0'; + ++e; + } + if (*e != 'q') { + continue; + } + *cp = '\0'; + if (*f) { + ret = ::strptime(ret, f, ptm); + if (!ret) { + break; + } + } + unsigned long mul = NS_PER_SEC; + if (num == 0) { + num = INT_MAX; + } + tv_nsec = 0; + while (isdigit(*ret) && num && (mul > 1)) { + --num; + mul /= 10; + tv_nsec = tv_nsec + (*ret - '0') * mul; + ++ret; + } + } + f = cp = e; + ++f; + } + + if (ret) { + tv_sec = mktime(ptm); + return ret; + } + + // Upon error, place a known value into the class, the current time. +#ifdef __linux__ + *this = log_time(CLOCK_REALTIME); +#else + time(&now); + tv_sec = now; + tv_nsec = 0; +#endif + return ret; +} + +log_time log_time::operator-= (const timespec &T) { + // No concept of negative time, clamp to EPOCH + if (*this <= T) { + return *this = EPOCH; + } + + if (this->tv_nsec < (unsigned long int)T.tv_nsec) { + --this->tv_sec; + this->tv_nsec = NS_PER_SEC + this->tv_nsec - T.tv_nsec; + } else { + this->tv_nsec -= T.tv_nsec; + } + this->tv_sec -= T.tv_sec; + + return *this; +} + +log_time log_time::operator-= (const log_time &T) { + // No concept of negative time, clamp to EPOCH + if (*this <= T) { + return *this = EPOCH; + } + + if (this->tv_nsec < T.tv_nsec) { + --this->tv_sec; + this->tv_nsec = NS_PER_SEC + this->tv_nsec - T.tv_nsec; + } else { + this->tv_nsec -= T.tv_nsec; + } + this->tv_sec -= T.tv_sec; + + return *this; +} diff --git a/liblog/logd_write.c b/liblog/logd_write.c index 5766f8c..3171c78 100644 --- a/liblog/logd_write.c +++ b/liblog/logd_write.c @@ -13,41 +13,34 @@ * See the License for the specific language governing permissions and * limitations under the License. */ -#include <time.h> -#include <stdio.h> +#include <errno.h> +#include <fcntl.h> #ifdef HAVE_PTHREADS #include <pthread.h> #endif -#include <unistd.h> -#include <errno.h> -#include <fcntl.h> -#include <string.h> -#include <stdlib.h> #include <stdarg.h> -#include <sys/types.h> +#include <stdio.h> +#include <stdlib.h> +#include <string.h> #include <sys/stat.h> +#include <sys/types.h> +#if (FAKE_LOG_DEVICE == 0) +#include <sys/socket.h> +#include <sys/un.h> +#endif +#include <time.h> +#include <unistd.h> -#include <log/logger.h> #include <log/logd.h> -#include <log/log.h> - -#define LOGGER_LOG_MAIN "log/main" -#define LOGGER_LOG_RADIO "log/radio" -#define LOGGER_LOG_EVENTS "log/events" -#define LOGGER_LOG_SYSTEM "log/system" +#include <log/logger.h> +#include <log/log_read.h> +#include <private/android_filesystem_config.h> #define LOG_BUF_SIZE 1024 #if FAKE_LOG_DEVICE -// This will be defined when building for the host. +/* This will be defined when building for the host. */ #include "fake_log_device.h" -#define log_open(pathname, flags) fakeLogOpen(pathname, flags) -#define log_writev(filedes, vector, count) fakeLogWritev(filedes, vector, count) -#define log_close(filedes) fakeLogClose(filedes) -#else -#define log_open(pathname, flags) open(pathname, (flags) | O_CLOEXEC) -#define log_writev(filedes, vector, count) writev(filedes, vector, count) -#define log_close(filedes) close(filedes) #endif static int __write_to_log_init(log_id_t, struct iovec *vec, size_t nr); @@ -56,13 +49,20 @@ static int (*write_to_log)(log_id_t, struct iovec *vec, size_t nr) = __write_to_ static pthread_mutex_t log_init_lock = PTHREAD_MUTEX_INITIALIZER; #endif -#define UNUSED __attribute__((__unused__)) +#ifndef __unused +#define __unused __attribute__((__unused__)) +#endif -static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1 }; +#if FAKE_LOG_DEVICE +#define WEAK __attribute__((weak)) +static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1, -1 }; +#else +static int logd_fd = -1; +#endif /* * This is used by the C++ code to decide if it should write logs through - * the C code. Basically, if /dev/log/... is available, we're running in + * the C code. Basically, if /dev/socket/logd is available, we're running in * the simulator rather than a desktop tool and want to use the device. */ static enum { @@ -71,7 +71,7 @@ static enum { int __android_log_dev_available(void) { if (g_log_status == kLogUninitialized) { - if (access("/dev/"LOGGER_LOG_MAIN, W_OK) == 0) + if (access("/dev/socket/logdw", W_OK) == 0) g_log_status = kLogAvailable; else g_log_status = kLogNotAvailable; @@ -80,30 +80,205 @@ int __android_log_dev_available(void) return (g_log_status == kLogAvailable); } -static int __write_to_log_null(log_id_t log_fd UNUSED, struct iovec *vec UNUSED, - size_t nr UNUSED) +#if !FAKE_LOG_DEVICE +/* give up, resources too limited */ +static int __write_to_log_null(log_id_t log_fd __unused, struct iovec *vec __unused, + size_t nr __unused) { return -1; } +#endif + +/* log_init_lock assumed */ +static int __write_to_log_initialize() +{ + int i, ret = 0; + +#if FAKE_LOG_DEVICE + for (i = 0; i < LOG_ID_MAX; i++) { + char buf[sizeof("/dev/log_system")]; + snprintf(buf, sizeof(buf), "/dev/log_%s", android_log_id_to_name(i)); + log_fds[i] = fakeLogOpen(buf, O_WRONLY); + } +#else + if (logd_fd >= 0) { + i = logd_fd; + logd_fd = -1; + close(i); + } + + i = socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0); + if (i < 0) { + ret = -errno; + write_to_log = __write_to_log_null; + } else if (fcntl(i, F_SETFL, O_NONBLOCK) < 0) { + ret = -errno; + close(i); + i = -1; + write_to_log = __write_to_log_null; + } else { + struct sockaddr_un un; + memset(&un, 0, sizeof(struct sockaddr_un)); + un.sun_family = AF_UNIX; + strcpy(un.sun_path, "/dev/socket/logdw"); + + if (connect(i, (struct sockaddr *)&un, sizeof(struct sockaddr_un)) < 0) { + ret = -errno; + close(i); + i = -1; + } + } + logd_fd = i; +#endif + + return ret; +} static int __write_to_log_kernel(log_id_t log_id, struct iovec *vec, size_t nr) { ssize_t ret; +#if FAKE_LOG_DEVICE int log_fd; if (/*(int)log_id >= 0 &&*/ (int)log_id < (int)LOG_ID_MAX) { log_fd = log_fds[(int)log_id]; } else { - return EBADF; + return -EBADF; } - do { - ret = log_writev(log_fd, vec, nr); - } while (ret < 0 && errno == EINTR); + ret = fakeLogWritev(log_fd, vec, nr); + if (ret < 0) { + ret = -errno; + } + } while (ret == -EINTR); +#else + static const unsigned header_length = 3; + struct iovec newVec[nr + header_length]; + typeof_log_id_t log_id_buf; + uint16_t tid; + struct timespec ts; + log_time realtime_ts; + size_t i, payload_size; + static uid_t last_uid = AID_ROOT; /* logd *always* starts up as AID_ROOT */ + + if (last_uid == AID_ROOT) { /* have we called to get the UID yet? */ + last_uid = getuid(); + } + if (last_uid == AID_LOGD) { /* logd, after initialization and priv drop */ + /* + * ignore log messages we send to ourself (logd). + * Such log messages are often generated by libraries we depend on + * which use standard Android logging. + */ + return 0; + } + + if (logd_fd < 0) { + return -EBADF; + } + + /* + * struct { + * // what we provide + * typeof_log_id_t log_id; + * u16 tid; + * log_time realtime; + * // caller provides + * union { + * struct { + * char prio; + * char payload[]; + * } string; + * struct { + * uint32_t tag + * char payload[]; + * } binary; + * }; + * }; + */ + + clock_gettime(CLOCK_REALTIME, &ts); + realtime_ts.tv_sec = ts.tv_sec; + realtime_ts.tv_nsec = ts.tv_nsec; + + log_id_buf = log_id; + tid = gettid(); + + newVec[0].iov_base = (unsigned char *) &log_id_buf; + newVec[0].iov_len = sizeof_log_id_t; + newVec[1].iov_base = (unsigned char *) &tid; + newVec[1].iov_len = sizeof(tid); + newVec[2].iov_base = (unsigned char *) &realtime_ts; + newVec[2].iov_len = sizeof(log_time); + + 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; + + if (payload_size > LOGGER_ENTRY_MAX_PAYLOAD) { + newVec[i].iov_len -= payload_size - LOGGER_ENTRY_MAX_PAYLOAD; + if (newVec[i].iov_len) { + ++i; + } + break; + } + } + + /* + * The write below could be lost, but will never block. + * + * ENOTCONN occurs if logd dies. + * EAGAIN occurs if logd is overloaded. + */ + ret = writev(logd_fd, newVec, i); + if (ret < 0) { + ret = -errno; + if (ret == -ENOTCONN) { +#ifdef HAVE_PTHREADS + pthread_mutex_lock(&log_init_lock); +#endif + ret = __write_to_log_initialize(); +#ifdef HAVE_PTHREADS + pthread_mutex_unlock(&log_init_lock); +#endif + + if (ret < 0) { + return ret; + } + + ret = writev(logd_fd, newVec, nr + header_length); + if (ret < 0) { + ret = -errno; + } + } + } + + if (ret > (ssize_t)(sizeof_log_id_t + sizeof(tid) + sizeof(log_time))) { + ret -= sizeof_log_id_t + sizeof(tid) + sizeof(log_time); + } +#endif return ret; } +#if FAKE_LOG_DEVICE +static const char *LOG_NAME[LOG_ID_MAX] = { + [LOG_ID_MAIN] = "main", + [LOG_ID_RADIO] = "radio", + [LOG_ID_EVENTS] = "events", + [LOG_ID_SYSTEM] = "system", + [LOG_ID_CRASH] = "crash" +}; + +const WEAK char *android_log_id_to_name(log_id_t log_id) +{ + if (log_id >= LOG_ID_MAX) { + log_id = LOG_ID_MAIN; + } + return LOG_NAME[log_id]; +} +#endif + static int __write_to_log_init(log_id_t log_id, struct iovec *vec, size_t nr) { #ifdef HAVE_PTHREADS @@ -111,27 +286,17 @@ static int __write_to_log_init(log_id_t log_id, struct iovec *vec, size_t nr) #endif if (write_to_log == __write_to_log_init) { - log_fds[LOG_ID_MAIN] = log_open("/dev/"LOGGER_LOG_MAIN, O_WRONLY); - log_fds[LOG_ID_RADIO] = log_open("/dev/"LOGGER_LOG_RADIO, O_WRONLY); - log_fds[LOG_ID_EVENTS] = log_open("/dev/"LOGGER_LOG_EVENTS, O_WRONLY); - log_fds[LOG_ID_SYSTEM] = log_open("/dev/"LOGGER_LOG_SYSTEM, O_WRONLY); - - write_to_log = __write_to_log_kernel; + int ret; - if (log_fds[LOG_ID_MAIN] < 0 || log_fds[LOG_ID_RADIO] < 0 || - log_fds[LOG_ID_EVENTS] < 0) { - log_close(log_fds[LOG_ID_MAIN]); - log_close(log_fds[LOG_ID_RADIO]); - log_close(log_fds[LOG_ID_EVENTS]); - log_fds[LOG_ID_MAIN] = -1; - log_fds[LOG_ID_RADIO] = -1; - log_fds[LOG_ID_EVENTS] = -1; - write_to_log = __write_to_log_null; + ret = __write_to_log_initialize(); + if (ret < 0) { +#ifdef HAVE_PTHREADS + pthread_mutex_unlock(&log_init_lock); +#endif + return ret; } - if (log_fds[LOG_ID_SYSTEM] < 0) { - log_fds[LOG_ID_SYSTEM] = log_fds[LOG_ID_MAIN]; - } + write_to_log = __write_to_log_kernel; } #ifdef HAVE_PTHREADS @@ -161,11 +326,18 @@ int __android_log_write(int prio, const char *tag, const char *msg) !strcmp(tag, "PHONE") || !strcmp(tag, "SMS")) { log_id = LOG_ID_RADIO; - // Inform third party apps/ril/radio.. to use Rlog or RLOG + /* Inform third party apps/ril/radio.. to use Rlog or RLOG */ snprintf(tmp_tag, sizeof(tmp_tag), "use-Rlog/RLOG-%s", tag); tag = tmp_tag; } +#if __BIONIC__ + if (prio == ANDROID_LOG_FATAL) { + extern void __android_set_abort_message(const char*); + __android_set_abort_message(msg); + } +#endif + vec[0].iov_base = (unsigned char *) &prio; vec[0].iov_len = 1; vec[1].iov_base = (void *) tag; @@ -196,7 +368,7 @@ int __android_log_buf_write(int bufID, int prio, const char *tag, const char *ms !strcmp(tag, "PHONE") || !strcmp(tag, "SMS"))) { bufID = LOG_ID_RADIO; - // Inform third party apps/ril/radio.. to use Rlog or RLOG + /* Inform third party apps/ril/radio.. to use Rlog or RLOG */ snprintf(tmp_tag, sizeof(tmp_tag), "use-Rlog/RLOG-%s", tag); tag = tmp_tag; } @@ -266,8 +438,8 @@ void __android_log_assert(const char *cond, const char *tag, } __android_log_write(ANDROID_LOG_FATAL, tag, buf); - __builtin_trap(); /* trap so we have a chance to debug the situation */ + /* NOTREACHED */ } int __android_log_bwrite(int32_t tag, const void *payload, size_t len) @@ -288,7 +460,7 @@ int __android_log_bwrite(int32_t tag, const void *payload, size_t len) * handy if we just want to dump an integer into the log. */ int __android_log_btwrite(int32_t tag, char type, const void *payload, - size_t len) + size_t len) { struct iovec vec[3]; @@ -301,3 +473,25 @@ int __android_log_btwrite(int32_t tag, char type, const void *payload, return write_to_log(LOG_ID_EVENTS, vec, 3); } + +/* + * Like __android_log_bwrite, but used for writing strings to the + * event log. + */ +int __android_log_bswrite(int32_t tag, const char *payload) +{ + struct iovec vec[4]; + char type = EVENT_TYPE_STRING; + uint32_t len = strlen(payload); + + vec[0].iov_base = &tag; + vec[0].iov_len = sizeof(tag); + vec[1].iov_base = &type; + vec[1].iov_len = sizeof(type); + vec[2].iov_base = &len; + vec[2].iov_len = sizeof(len); + vec[3].iov_base = (void*)payload; + vec[3].iov_len = len; + + return write_to_log(LOG_ID_EVENTS, vec, 4); +} diff --git a/liblog/logd_write_kern.c b/liblog/logd_write_kern.c new file mode 100644 index 0000000..1ed5ecf --- /dev/null +++ b/liblog/logd_write_kern.c @@ -0,0 +1,341 @@ +/* + * Copyright (C) 2007-2014 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include <errno.h> +#include <fcntl.h> +#ifdef HAVE_PTHREADS +#include <pthread.h> +#endif +#include <stdarg.h> +#include <stdio.h> +#include <stdlib.h> +#include <string.h> +#include <sys/stat.h> +#include <sys/types.h> +#include <time.h> +#include <unistd.h> + +#include <log/log.h> +#include <log/logd.h> +#include <log/logger.h> + +#define LOGGER_LOG_MAIN "log/main" +#define LOGGER_LOG_RADIO "log/radio" +#define LOGGER_LOG_EVENTS "log/events" +#define LOGGER_LOG_SYSTEM "log/system" + +#define LOG_BUF_SIZE 1024 + +#if FAKE_LOG_DEVICE +/* This will be defined when building for the host. */ +#include "fake_log_device.h" +#define log_open(pathname, flags) fakeLogOpen(pathname, flags) +#define log_writev(filedes, vector, count) fakeLogWritev(filedes, vector, count) +#define log_close(filedes) fakeLogClose(filedes) +#else +#define log_open(pathname, flags) open(pathname, (flags) | O_CLOEXEC) +#define log_writev(filedes, vector, count) writev(filedes, vector, count) +#define log_close(filedes) close(filedes) +#endif + +static int __write_to_log_init(log_id_t, struct iovec *vec, size_t nr); +static int (*write_to_log)(log_id_t, struct iovec *vec, size_t nr) = __write_to_log_init; +#ifdef HAVE_PTHREADS +static pthread_mutex_t log_init_lock = PTHREAD_MUTEX_INITIALIZER; +#endif + +#ifndef __unused +#define __unused __attribute__((__unused__)) +#endif + +static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1 }; + +/* + * This is used by the C++ code to decide if it should write logs through + * the C code. Basically, if /dev/log/... is available, we're running in + * the simulator rather than a desktop tool and want to use the device. + */ +static enum { + kLogUninitialized, kLogNotAvailable, kLogAvailable +} g_log_status = kLogUninitialized; +int __android_log_dev_available(void) +{ + if (g_log_status == kLogUninitialized) { + if (access("/dev/"LOGGER_LOG_MAIN, W_OK) == 0) + g_log_status = kLogAvailable; + else + g_log_status = kLogNotAvailable; + } + + return (g_log_status == kLogAvailable); +} + +static int __write_to_log_null(log_id_t log_fd __unused, struct iovec *vec __unused, + size_t nr __unused) +{ + return -1; +} + +static int __write_to_log_kernel(log_id_t log_id, struct iovec *vec, size_t nr) +{ + ssize_t ret; + int log_fd; + + if (/*(int)log_id >= 0 &&*/ (int)log_id < (int)LOG_ID_MAX) { + if (log_id == LOG_ID_CRASH) { + log_id = LOG_ID_MAIN; + } + log_fd = log_fds[(int)log_id]; + } else { + return -EBADF; + } + + do { + ret = log_writev(log_fd, vec, nr); + if (ret < 0) { + ret = -errno; + } + } while (ret == -EINTR); + + return ret; +} + +static int __write_to_log_init(log_id_t log_id, struct iovec *vec, size_t nr) +{ +#ifdef HAVE_PTHREADS + pthread_mutex_lock(&log_init_lock); +#endif + + if (write_to_log == __write_to_log_init) { + log_fds[LOG_ID_MAIN] = log_open("/dev/"LOGGER_LOG_MAIN, O_WRONLY); + log_fds[LOG_ID_RADIO] = log_open("/dev/"LOGGER_LOG_RADIO, O_WRONLY); + log_fds[LOG_ID_EVENTS] = log_open("/dev/"LOGGER_LOG_EVENTS, O_WRONLY); + log_fds[LOG_ID_SYSTEM] = log_open("/dev/"LOGGER_LOG_SYSTEM, O_WRONLY); + + write_to_log = __write_to_log_kernel; + + if (log_fds[LOG_ID_MAIN] < 0 || log_fds[LOG_ID_RADIO] < 0 || + log_fds[LOG_ID_EVENTS] < 0) { + log_close(log_fds[LOG_ID_MAIN]); + log_close(log_fds[LOG_ID_RADIO]); + log_close(log_fds[LOG_ID_EVENTS]); + log_fds[LOG_ID_MAIN] = -1; + log_fds[LOG_ID_RADIO] = -1; + log_fds[LOG_ID_EVENTS] = -1; + write_to_log = __write_to_log_null; + } + + if (log_fds[LOG_ID_SYSTEM] < 0) { + log_fds[LOG_ID_SYSTEM] = log_fds[LOG_ID_MAIN]; + } + } + +#ifdef HAVE_PTHREADS + pthread_mutex_unlock(&log_init_lock); +#endif + + return write_to_log(log_id, vec, nr); +} + +int __android_log_write(int prio, const char *tag, const char *msg) +{ + struct iovec vec[3]; + log_id_t log_id = LOG_ID_MAIN; + char tmp_tag[32]; + + if (!tag) + tag = ""; + + /* XXX: This needs to go! */ + if (!strcmp(tag, "HTC_RIL") || + !strncmp(tag, "RIL", 3) || /* Any log tag with "RIL" as the prefix */ + !strncmp(tag, "IMS", 3) || /* Any log tag with "IMS" as the prefix */ + !strcmp(tag, "AT") || + !strcmp(tag, "GSM") || + !strcmp(tag, "STK") || + !strcmp(tag, "CDMA") || + !strcmp(tag, "PHONE") || + !strcmp(tag, "SMS")) { + log_id = LOG_ID_RADIO; + /* Inform third party apps/ril/radio.. to use Rlog or RLOG */ + snprintf(tmp_tag, sizeof(tmp_tag), "use-Rlog/RLOG-%s", tag); + tag = tmp_tag; + } + +#if __BIONIC__ + if (prio == ANDROID_LOG_FATAL) { + extern void __android_set_abort_message(const char*); + __android_set_abort_message(msg); + } +#endif + + vec[0].iov_base = (unsigned char *) &prio; + vec[0].iov_len = 1; + vec[1].iov_base = (void *) tag; + vec[1].iov_len = strlen(tag) + 1; + vec[2].iov_base = (void *) msg; + vec[2].iov_len = strlen(msg) + 1; + + return write_to_log(log_id, vec, 3); +} + +int __android_log_buf_write(int bufID, int prio, const char *tag, const char *msg) +{ + struct iovec vec[3]; + char tmp_tag[32]; + + if (!tag) + tag = ""; + + /* XXX: This needs to go! */ + if ((bufID != LOG_ID_RADIO) && + (!strcmp(tag, "HTC_RIL") || + !strncmp(tag, "RIL", 3) || /* Any log tag with "RIL" as the prefix */ + !strncmp(tag, "IMS", 3) || /* Any log tag with "IMS" as the prefix */ + !strcmp(tag, "AT") || + !strcmp(tag, "GSM") || + !strcmp(tag, "STK") || + !strcmp(tag, "CDMA") || + !strcmp(tag, "PHONE") || + !strcmp(tag, "SMS"))) { + bufID = LOG_ID_RADIO; + /* Inform third party apps/ril/radio.. to use Rlog or RLOG */ + snprintf(tmp_tag, sizeof(tmp_tag), "use-Rlog/RLOG-%s", tag); + tag = tmp_tag; + } + + vec[0].iov_base = (unsigned char *) &prio; + vec[0].iov_len = 1; + vec[1].iov_base = (void *) tag; + vec[1].iov_len = strlen(tag) + 1; + vec[2].iov_base = (void *) msg; + vec[2].iov_len = strlen(msg) + 1; + + return write_to_log(bufID, vec, 3); +} + +int __android_log_vprint(int prio, const char *tag, const char *fmt, va_list ap) +{ + char buf[LOG_BUF_SIZE]; + + vsnprintf(buf, LOG_BUF_SIZE, fmt, ap); + + return __android_log_write(prio, tag, buf); +} + +int __android_log_print(int prio, const char *tag, const char *fmt, ...) +{ + va_list ap; + char buf[LOG_BUF_SIZE]; + + va_start(ap, fmt); + vsnprintf(buf, LOG_BUF_SIZE, fmt, ap); + va_end(ap); + + return __android_log_write(prio, tag, buf); +} + +int __android_log_buf_print(int bufID, int prio, const char *tag, const char *fmt, ...) +{ + va_list ap; + char buf[LOG_BUF_SIZE]; + + va_start(ap, fmt); + vsnprintf(buf, LOG_BUF_SIZE, fmt, ap); + va_end(ap); + + return __android_log_buf_write(bufID, prio, tag, buf); +} + +void __android_log_assert(const char *cond, const char *tag, + const char *fmt, ...) +{ + char buf[LOG_BUF_SIZE]; + + if (fmt) { + va_list ap; + va_start(ap, fmt); + vsnprintf(buf, LOG_BUF_SIZE, fmt, ap); + va_end(ap); + } else { + /* Msg not provided, log condition. N.B. Do not use cond directly as + * format string as it could contain spurious '%' syntax (e.g. + * "%d" in "blocks%devs == 0"). + */ + if (cond) + snprintf(buf, LOG_BUF_SIZE, "Assertion failed: %s", cond); + else + strcpy(buf, "Unspecified assertion failed"); + } + + __android_log_write(ANDROID_LOG_FATAL, tag, buf); + __builtin_trap(); /* trap so we have a chance to debug the situation */ + /* NOTREACHED */ +} + +int __android_log_bwrite(int32_t tag, const void *payload, size_t len) +{ + struct iovec vec[2]; + + vec[0].iov_base = &tag; + vec[0].iov_len = sizeof(tag); + vec[1].iov_base = (void*)payload; + vec[1].iov_len = len; + + return write_to_log(LOG_ID_EVENTS, vec, 2); +} + +/* + * Like __android_log_bwrite, but takes the type as well. Doesn't work + * for the general case where we're generating lists of stuff, but very + * handy if we just want to dump an integer into the log. + */ +int __android_log_btwrite(int32_t tag, char type, const void *payload, + size_t len) +{ + struct iovec vec[3]; + + vec[0].iov_base = &tag; + vec[0].iov_len = sizeof(tag); + vec[1].iov_base = &type; + vec[1].iov_len = sizeof(type); + vec[2].iov_base = (void*)payload; + vec[2].iov_len = len; + + return write_to_log(LOG_ID_EVENTS, vec, 3); +} + +/* + * Like __android_log_bwrite, but used for writing strings to the + * event log. + */ +int __android_log_bswrite(int32_t tag, const char *payload) +{ + struct iovec vec[4]; + char type = EVENT_TYPE_STRING; + uint32_t len = strlen(payload); + + vec[0].iov_base = &tag; + vec[0].iov_len = sizeof(tag); + vec[1].iov_base = &type; + vec[1].iov_len = sizeof(type); + vec[2].iov_base = &len; + vec[2].iov_len = sizeof(len); + vec[3].iov_base = (void*)payload; + vec[3].iov_len = len; + + return write_to_log(LOG_ID_EVENTS, vec, 4); +} diff --git a/liblog/logprint.c b/liblog/logprint.c index a7480d5..08e830a 100644 --- a/liblog/logprint.c +++ b/liblog/logprint.c @@ -17,14 +17,14 @@ #define _GNU_SOURCE /* for asprintf */ +#include <arpa/inet.h> +#include <assert.h> #include <ctype.h> -#include <stdio.h> #include <errno.h> -#include <stdlib.h> #include <stdint.h> +#include <stdio.h> +#include <stdlib.h> #include <string.h> -#include <assert.h> -#include <arpa/inet.h> #include <log/logd.h> #include <log/logprint.h> @@ -52,15 +52,7 @@ static FilterInfo * filterinfo_new(const char * tag, android_LogPriority pri) return p_ret; } -static void filterinfo_free(FilterInfo *p_info) -{ - if (p_info == NULL) { - return; - } - - free(p_info->mTag); - p_info->mTag = NULL; -} +/* balance to above, filterinfo_free left unimplemented */ /* * Note: also accepts 0-9 priorities @@ -139,23 +131,6 @@ static android_LogPriority filterPriForTag( return p_format->global_pri; } -/** for debugging */ -static void dumpFilters(AndroidLogFormat *p_format) -{ - FilterInfo *p_fi; - - for (p_fi = p_format->filters ; p_fi != NULL ; p_fi = p_fi->p_next) { - char cPri = filterPriToChar(p_fi->mPri); - if (p_fi->mPri == ANDROID_LOG_DEFAULT) { - cPri = filterPriToChar(p_format->global_pri); - } - fprintf(stderr,"%s:%c\n", p_fi->mTag, cPri); - } - - fprintf(stderr,"*:%c\n", filterPriToChar(p_format->global_pri)); - -} - /** * returns 1 if this log line should be printed based on its priority * and tag, and 0 if it should not @@ -234,7 +209,6 @@ AndroidLogPrintFormat android_log_formatFromString(const char * formatString) int android_log_addFilterRule(AndroidLogFormat *p_format, const char *filterExpression) { - size_t i=0; size_t tagNameLength; android_LogPriority pri = ANDROID_LOG_DEFAULT; @@ -718,7 +692,6 @@ char *android_log_formatLogLine ( #endif struct tm* ptm; char timeBuf[32]; - char headerBuf[128]; char prefixBuf[128], suffixBuf[128]; char priChar; int prefixSuffixIsHeaderFooter = 0; @@ -817,7 +790,6 @@ char *android_log_formatLogLine ( /* the following code is tragically unreadable */ size_t numLines; - size_t i; char *p; size_t bufferSize; const char *pm; @@ -938,88 +910,3 @@ done: return ret; } - - - -void logprint_run_tests() -{ -#if 0 - - fprintf(stderr, "tests disabled\n"); - -#else - - int err; - const char *tag; - AndroidLogFormat *p_format; - - p_format = android_log_format_new(); - - fprintf(stderr, "running tests\n"); - - tag = "random"; - - android_log_addFilterRule(p_format,"*:i"); - - assert (ANDROID_LOG_INFO == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); - android_log_addFilterRule(p_format, "*"); - assert (ANDROID_LOG_DEBUG == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); - android_log_addFilterRule(p_format, "*:v"); - assert (ANDROID_LOG_VERBOSE == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); - android_log_addFilterRule(p_format, "*:i"); - assert (ANDROID_LOG_INFO == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); - - android_log_addFilterRule(p_format, "random"); - assert (ANDROID_LOG_VERBOSE == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); - android_log_addFilterRule(p_format, "random:v"); - assert (ANDROID_LOG_VERBOSE == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); - android_log_addFilterRule(p_format, "random:d"); - assert (ANDROID_LOG_DEBUG == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); - android_log_addFilterRule(p_format, "random:w"); - assert (ANDROID_LOG_WARN == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); - - android_log_addFilterRule(p_format, "crap:*"); - assert (ANDROID_LOG_VERBOSE== filterPriForTag(p_format, "crap")); - assert(android_log_shouldPrintLine(p_format, "crap", ANDROID_LOG_VERBOSE) > 0); - - // invalid expression - err = android_log_addFilterRule(p_format, "random:z"); - assert (err < 0); - assert (ANDROID_LOG_WARN == filterPriForTag(p_format, "random")); - assert(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); - - // Issue #550946 - err = android_log_addFilterString(p_format, " "); - assert(err == 0); - assert(ANDROID_LOG_WARN == filterPriForTag(p_format, "random")); - - // note trailing space - err = android_log_addFilterString(p_format, "*:s random:d "); - assert(err == 0); - assert(ANDROID_LOG_DEBUG == filterPriForTag(p_format, "random")); - - err = android_log_addFilterString(p_format, "*:s random:z"); - assert(err < 0); - - -#if 0 - char *ret; - char defaultBuffer[512]; - - ret = android_log_formatLogLine(p_format, - defaultBuffer, sizeof(defaultBuffer), 0, ANDROID_LOG_ERROR, 123, - 123, 123, "random", "nofile", strlen("Hello"), "Hello", NULL); -#endif - - - fprintf(stderr, "tests complete\n"); -#endif -} diff --git a/liblog/tests/Android.mk b/liblog/tests/Android.mk index db06cf7..255dc2e 100644 --- a/liblog/tests/Android.mk +++ b/liblog/tests/Android.mk @@ -32,7 +32,7 @@ benchmark_c_flags := \ benchmark_src_files := \ benchmark_main.cpp \ - liblog_benchmark.cpp \ + liblog_benchmark.cpp # Build benchmarks for the device. Run with: # adb shell liblog-benchmarks @@ -59,10 +59,22 @@ test_c_flags := \ -g \ -Wall -Wextra \ -Werror \ - -fno-builtin \ + -fno-builtin test_src_files := \ - liblog_test.cpp \ + liblog_test.cpp + +# to prevent breaking the build if bionic not relatively visible to us +ifneq ($(wildcard $(LOCAL_PATH)/../../../../bionic/libc/bionic/libc_logging.cpp),) + +test_src_files += \ + libc_test.cpp + +ifndef ($(TARGET_USES_LOGD),false) +test_c_flags += -DTARGET_USES_LOGD +endif + +endif # Build tests for the device (with .so). Run with: # adb shell /data/nativetest/liblog-unit-tests/liblog-unit-tests @@ -71,7 +83,6 @@ LOCAL_MODULE := $(test_module_prefix)unit-tests LOCAL_MODULE_TAGS := $(test_tags) LOCAL_ADDITIONAL_DEPENDENCIES := $(LOCAL_PATH)/Android.mk LOCAL_CFLAGS += $(test_c_flags) -LOCAL_LDLIBS := -lpthread LOCAL_SHARED_LIBRARIES := liblog LOCAL_SRC_FILES := $(test_src_files) include $(BUILD_NATIVE_TEST) diff --git a/liblog/tests/benchmark_main.cpp b/liblog/tests/benchmark_main.cpp index 02df460..090394c 100644 --- a/liblog/tests/benchmark_main.cpp +++ b/liblog/tests/benchmark_main.cpp @@ -16,6 +16,7 @@ #include <benchmark.h> +#include <inttypes.h> #include <regex.h> #include <stdio.h> #include <stdlib.h> @@ -158,10 +159,10 @@ void Run(Benchmark* b) { sdev = (sqrt((double)nXvariance) / gBenchmarkNum / gBenchmarkNum) + 0.5; } if (mean > (10000 * sdev)) { - printf("%-25s %10llu %10llu%s\n", full_name, + printf("%-25s %10" PRIu64 " %10" PRIu64 "%s\n", full_name, static_cast<uint64_t>(iterations), mean, throughput); } else { - printf("%-25s %10llu %10llu(\317\203%llu)%s\n", full_name, + printf("%-25s %10" PRIu64 " %10" PRIu64 "(\317\203%" PRIu64 ")%s\n", full_name, static_cast<uint64_t>(iterations), mean, sdev, throughput); } fflush(stdout); diff --git a/liblog/tests/libc_test.cpp b/liblog/tests/libc_test.cpp new file mode 100644 index 0000000..9839729 --- /dev/null +++ b/liblog/tests/libc_test.cpp @@ -0,0 +1,138 @@ +/* + * Copyright (C) 2014 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include <fcntl.h> +#include <sys/cdefs.h> + +#include <gtest/gtest.h> + +// Should be in bionic test suite, *but* we are using liblog to confirm +// end-to-end logging, so let the overly cute oedipus complex begin ... +#include "../../../../bionic/libc/bionic/libc_logging.cpp" // not Standalone +#define _ANDROID_LOG_H // Priorities redefined +#define _LIBS_LOG_LOG_H // log ids redefined +typedef unsigned char log_id_t; // log_id_t missing as a result +#ifdef TARGET_USES_LOGD +#define _LIBS_LOG_LOG_READ_H // log_time redefined +#endif + +#include <log/log.h> +#include <log/logger.h> +#include <log/log_read.h> + +TEST(libc, __libc_android_log_event_int) { + struct logger_list *logger_list; + + pid_t pid = getpid(); + + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( + LOG_ID_EVENTS, O_RDONLY | O_NDELAY, 1000, pid))); + + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + int value = ts.tv_nsec; + + __libc_android_log_event_int(0, value); + 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 != (4 + 1 + 4)) + || ((int)log_msg.id() != LOG_ID_EVENTS)) { + continue; + } + + char *eventData = log_msg.msg(); + + int incoming = (eventData[0] & 0xFF) | + ((eventData[1] & 0xFF) << 8) | + ((eventData[2] & 0xFF) << 16) | + ((eventData[3] & 0xFF) << 24); + + if (incoming != 0) { + continue; + } + + if (eventData[4] != EVENT_TYPE_INT) { + continue; + } + + incoming = (eventData[4 + 1 + 0] & 0xFF) | + ((eventData[4 + 1 + 1] & 0xFF) << 8) | + ((eventData[4 + 1 + 2] & 0xFF) << 16) | + ((eventData[4 + 1 + 3] & 0xFF) << 24); + + if (incoming == value) { + ++count; + } + } + + EXPECT_EQ(1, count); + + android_logger_list_close(logger_list); +} + +TEST(libc, __libc_fatal_no_abort) { + struct logger_list *logger_list; + + pid_t pid = getpid(); + + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( + (log_id_t)LOG_ID_CRASH, O_RDONLY | O_NDELAY, 1000, pid))); + + char b[80]; + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + + __libc_fatal_no_abort("%u.%09u", (unsigned)ts.tv_sec, (unsigned)ts.tv_nsec); + snprintf(b, sizeof(b),"%u.%09u", (unsigned)ts.tv_sec, (unsigned)ts.tv_nsec); + 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 ((int)log_msg.id() != LOG_ID_CRASH) { + continue; + } + + char *data = log_msg.msg(); + + if ((*data == ANDROID_LOG_FATAL) + && !strcmp(data + 1, "libc") + && !strcmp(data + 1 + strlen(data + 1) + 1, b)) { + ++count; + } + } + + EXPECT_EQ(1, count); + + android_logger_list_close(logger_list); +} diff --git a/liblog/tests/liblog_benchmark.cpp b/liblog/tests/liblog_benchmark.cpp index 19406fb..549d79e 100644 --- a/liblog/tests/liblog_benchmark.cpp +++ b/liblog/tests/liblog_benchmark.cpp @@ -99,7 +99,7 @@ static void BM_log_overhead(int iters) { } BENCHMARK(BM_log_overhead); -static void caught_latency(int signum) +static void caught_latency(int /*signum*/) { unsigned long long v = 0xDEADBEEFA55A5AA5ULL; @@ -143,7 +143,7 @@ static void BM_log_latency(int iters) { for (int j = 0, i = 0; i < iters && j < 10*iters; ++i, ++j) { log_time ts; LOG_FAILURE_RETRY(( - clock_gettime(CLOCK_REALTIME, &ts), + ts = log_time(CLOCK_REALTIME), android_btWriteLog(0, EVENT_TYPE_LONG, &ts, sizeof(ts)))); for (;;) { @@ -193,7 +193,7 @@ static void BM_log_latency(int iters) { } BENCHMARK(BM_log_latency); -static void caught_delay(int signum) +static void caught_delay(int /*signum*/) { unsigned long long v = 0xDEADBEEFA55A5AA6ULL; diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp index 9ae8f22..393e2cd 100644 --- a/liblog/tests/liblog_test.cpp +++ b/liblog/tests/liblog_test.cpp @@ -15,11 +15,13 @@ */ #include <fcntl.h> +#include <inttypes.h> #include <signal.h> #include <gtest/gtest.h> #include <log/log.h> #include <log/logger.h> #include <log/log_read.h> +#include <log/logprint.h> // 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 @@ -37,30 +39,30 @@ _rc; }) TEST(liblog, __android_log_buf_print) { - ASSERT_LT(0, __android_log_buf_print(LOG_ID_RADIO, ANDROID_LOG_INFO, + EXPECT_LT(0, __android_log_buf_print(LOG_ID_RADIO, ANDROID_LOG_INFO, "TEST__android_log_buf_print", "radio")); usleep(1000); - ASSERT_LT(0, __android_log_buf_print(LOG_ID_SYSTEM, ANDROID_LOG_INFO, + EXPECT_LT(0, __android_log_buf_print(LOG_ID_SYSTEM, ANDROID_LOG_INFO, "TEST__android_log_buf_print", "system")); usleep(1000); - ASSERT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, + EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, "TEST__android_log_buf_print", "main")); usleep(1000); } TEST(liblog, __android_log_buf_write) { - ASSERT_LT(0, __android_log_buf_write(LOG_ID_RADIO, ANDROID_LOG_INFO, + EXPECT_LT(0, __android_log_buf_write(LOG_ID_RADIO, ANDROID_LOG_INFO, "TEST__android_log_buf_write", "radio")); usleep(1000); - ASSERT_LT(0, __android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, + EXPECT_LT(0, __android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, "TEST__android_log_buf_write", "system")); usleep(1000); - ASSERT_LT(0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO, + EXPECT_LT(0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO, "TEST__android_log_buf_write", "main")); usleep(1000); @@ -68,16 +70,16 @@ TEST(liblog, __android_log_buf_write) { TEST(liblog, __android_log_btwrite) { int intBuf = 0xDEADBEEF; - ASSERT_LT(0, __android_log_btwrite(0, + EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_INT, &intBuf, sizeof(intBuf))); long long longBuf = 0xDEADBEEFA55A5AA5; - ASSERT_LT(0, __android_log_btwrite(0, + EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &longBuf, sizeof(longBuf))); usleep(1000); char Buf[] = "\20\0\0\0DeAdBeEfA55a5aA5"; - ASSERT_LT(0, __android_log_btwrite(0, + EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_STRING, Buf, sizeof(Buf) - 1)); usleep(1000); @@ -85,8 +87,8 @@ TEST(liblog, __android_log_btwrite) { static void* ConcurrentPrintFn(void *arg) { int ret = __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, - "TEST__android_log_print", "Concurrent %d", - reinterpret_cast<int>(arg)); + "TEST__android_log_print", "Concurrent %" PRIuPTR, + reinterpret_cast<uintptr_t>(arg)); return reinterpret_cast<void*>(ret); } @@ -106,8 +108,9 @@ TEST(liblog, concurrent_name(__android_log_buf_print, NUM_CONCURRENT)) { for (i=0; i < NUM_CONCURRENT; i++) { void* result; ASSERT_EQ(0, pthread_join(t[i], &result)); - if ((0 == ret) && (0 != reinterpret_cast<int>(result))) { - ret = reinterpret_cast<int>(result); + int this_result = reinterpret_cast<uintptr_t>(result); + if ((0 == ret) && (0 != this_result)) { + ret = this_result; } } ASSERT_LT(0, ret); @@ -118,7 +121,7 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { pid_t pid = getpid(); - ASSERT_EQ(0, NULL == (logger_list = android_logger_list_open( + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_EVENTS, O_RDONLY | O_NDELAY, 1000, pid))); log_time ts(CLOCK_MONOTONIC); @@ -153,7 +156,7 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { } } - ASSERT_EQ(1, count); + EXPECT_EQ(1, count); android_logger_list_close(logger_list); } @@ -161,7 +164,7 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { static unsigned signaled; log_time signal_time; -static void caught_blocking(int signum) +static void caught_blocking(int /*signum*/) { unsigned long long v = 0xDEADBEEFA55A0000ULL; @@ -169,7 +172,7 @@ static void caught_blocking(int signum) ++signaled; if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) { - clock_gettime(CLOCK_MONOTONIC, &signal_time); + signal_time = log_time(CLOCK_MONOTONIC); signal_time.tv_sec += 2; } @@ -219,7 +222,7 @@ TEST(liblog, android_logger_list_read__cpu) { v += pid & 0xFFFF; - ASSERT_EQ(0, NULL == (logger_list = android_logger_list_open( + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( LOG_ID_EVENTS, O_RDONLY, 1000, pid))); int count = 0; @@ -275,13 +278,13 @@ TEST(liblog, android_logger_list_read__cpu) { ++signals; break; } - } while (!signaled || ({log_time t(CLOCK_MONOTONIC); t < signal_time;})); + } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time)); alarm(0); signal(SIGALRM, SIG_DFL); - ASSERT_LT(1, count); + EXPECT_LT(1, count); - ASSERT_EQ(1, signals); + EXPECT_EQ(1, signals); android_logger_list_close(logger_list); @@ -293,9 +296,302 @@ TEST(liblog, android_logger_list_read__cpu) { const unsigned long long one_percent_ticks = alarm_time; unsigned long long user_ticks = uticks_end - uticks_start; unsigned long long system_ticks = sticks_end - sticks_start; - ASSERT_GT(one_percent_ticks, user_ticks); - ASSERT_GT(one_percent_ticks, system_ticks); - ASSERT_GT(one_percent_ticks, user_ticks + system_ticks); + EXPECT_GT(one_percent_ticks, user_ticks); + EXPECT_GT(one_percent_ticks, system_ticks); + EXPECT_GT(one_percent_ticks, user_ticks + system_ticks); +} + +static const char max_payload_tag[] = "TEST_max_payload_XXXX"; +static const char max_payload_buf[LOGGER_ENTRY_MAX_PAYLOAD + - sizeof(max_payload_tag) - 1] = "LEONATO\n\ +I learn in this letter that Don Peter of Arragon\n\ +comes this night to Messina\n\ +MESSENGER\n\ +He is very near by this: he was not three leagues off\n\ +when I left him\n\ +LEONATO\n\ +How many gentlemen have you lost in this action?\n\ +MESSENGER\n\ +But few of any sort, and none of name\n\ +LEONATO\n\ +A victory is twice itself when the achiever brings\n\ +home full numbers. I find here that Don Peter hath\n\ +bestowed much honour on a young Florentine called Claudio\n\ +MESSENGER\n\ +Much deserved on his part and equally remembered by\n\ +Don Pedro: he hath borne himself beyond the\n\ +promise of his age, doing, in the figure of a lamb,\n\ +the feats of a lion: he hath indeed better\n\ +bettered expectation than you must expect of me to\n\ +tell you how\n\ +LEONATO\n\ +He hath an uncle here in Messina will be very much\n\ +glad of it.\n\ +MESSENGER\n\ +I have already delivered him letters, and there\n\ +appears much joy in him; even so much that joy could\n\ +not show itself modest enough without a badge of\n\ +bitterness.\n\ +LEONATO\n\ +Did he break out into tears?\n\ +MESSENGER\n\ +In great measure.\n\ +LEONATO\n\ +A kind overflow of kindness: there are no faces\n\ +truer than those that are so washed. How much\n\ +better is it to weep at joy than to joy at weeping!\n\ +BEATRICE\n\ +I pray you, is Signior Mountanto returned from the\n\ +wars or no?\n\ +MESSENGER\n\ +I know none of that name, lady: there was none such\n\ +in the army of any sort.\n\ +LEONATO\n\ +What is he that you ask for, niece?\n\ +HERO\n\ +My cousin means Signior Benedick of Padua.\n\ +MESSENGER\n\ +O, he's returned; and as pleasant as ever he was.\n\ +BEATRICE\n\ +He set up his bills here in Messina and challenged\n\ +Cupid at the flight; and my uncle's fool, reading\n\ +the challenge, subscribed for Cupid, and challenged\n\ +him at the bird-bolt. I pray you, how many hath he\n\ +killed and eaten in these wars? But how many hath\n\ +he killed? for indeed I promised to eat all of his killing.\n\ +LEONATO\n\ +Faith, niece, you tax Signior Benedick too much;\n\ +but he'll be meet with you, I doubt it not.\n\ +MESSENGER\n\ +He hath done good service, lady, in these wars.\n\ +BEATRICE\n\ +You had musty victual, and he hath holp to eat it:\n\ +he is a very valiant trencherman; he hath an\n\ +excellent stomach.\n\ +MESSENGER\n\ +And a good soldier too, lady.\n\ +BEATRICE\n\ +And a good soldier to a lady: but what is he to a lord?\n\ +MESSENGER\n\ +A lord to a lord, a man to a man; stuffed with all\n\ +honourable virtues.\n\ +BEATRICE\n\ +It is so, indeed; he is no less than a stuffed man:\n\ +but for the stuffing,--well, we are all mortal.\n\ +LEONATO\n\ +You must not, sir, mistake my niece. There is a\n\ +kind of merry war betwixt Signior Benedick and her:\n\ +they never meet but there's a skirmish of wit\n\ +between them.\n\ +BEATRICE\n\ +Alas! he gets nothing by that. In our last\n\ +conflict four of his five wits went halting off, and\n\ +now is the whole man governed with one: so that if\n\ +he have wit enough to keep himself warm, let him\n\ +bear it for a difference between himself and his\n\ +horse; for it is all the wealth that he hath left,\n\ +to be known a reasonable creature. Who is his\n\ +companion now? He hath every month a new sworn brother.\n\ +MESSENGER\n\ +Is't possible?\n\ +BEATRICE\n\ +Very easily possible: he wears his faith but as\n\ +the fashion of his hat; it ever changes with the\n\ +next block.\n\ +MESSENGER\n\ +I see, lady, the gentleman is not in your books.\n\ +BEATRICE\n\ +No; an he were, I would burn my study. But, I pray\n\ +you, who is his companion? Is there no young\n\ +squarer now that will make a voyage with him to the devil?\n\ +MESSENGER\n\ +He is most in the company of the right noble Claudio.\n\ +BEATRICE\n\ +O Lord, he will hang upon him like a disease: he\n\ +is sooner caught than the pestilence, and the taker\n\ +runs presently mad. God help the noble Claudio! if\n\ +he have caught the Benedick, it will cost him a\n\ +thousand pound ere a' be cured.\n\ +MESSENGER\n\ +I will hold friends with you, lady.\n\ +BEATRICE\n\ +Do, good friend.\n\ +LEONATO\n\ +You will never run mad, niece.\n\ +BEATRICE\n\ +No, not till a hot January.\n\ +MESSENGER\n\ +Don Pedro is approached.\n\ +Enter DON PEDRO, DON JOHN, CLAUDIO, BENEDICK, and BALTHASAR\n\ +\n\ +DON PEDRO\n\ +Good Signior Leonato, you are come to meet your\n\ +trouble: the fashion of the world is to avoid\n\ +cost, and you encounter it\n\ +LEONATO\n\ +Never came trouble to my house in the likeness"; + +TEST(liblog, max_payload) { + pid_t pid = getpid(); + char tag[sizeof(max_payload_tag)]; + memcpy(tag, max_payload_tag, sizeof(tag)); + snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF); + + LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, + tag, max_payload_buf)); + + struct logger_list *logger_list; + + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( + LOG_ID_SYSTEM, O_RDONLY, 100, 0))); + + bool matches = false; + ssize_t max_len = 0; + + for(;;) { + log_msg log_msg; + if (android_logger_list_read(logger_list, &log_msg) <= 0) { + break; + } + + if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) { + continue; + } + + char *data = log_msg.msg() + 1; + + if (strcmp(data, tag)) { + continue; + } + + data += strlen(data) + 1; + + const char *left = data; + const char *right = max_payload_buf; + while (*left && *right && (*left == *right)) { + ++left; + ++right; + } + + if (max_len <= (left - data)) { + max_len = left - data + 1; + } + + if (max_len > 512) { + matches = true; + break; + } + } + + android_logger_list_close(logger_list); + + EXPECT_EQ(true, matches); + + EXPECT_LE(sizeof(max_payload_buf), static_cast<size_t>(max_len)); +} + +TEST(liblog, too_big_payload) { + pid_t pid = getpid(); + static const char big_payload_tag[] = "TEST_big_payload_XXXX"; + char tag[sizeof(big_payload_tag)]; + memcpy(tag, big_payload_tag, sizeof(tag)); + snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF); + + std::string longString(3266519, 'x'); + + ssize_t ret = LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM, + ANDROID_LOG_INFO, tag, longString.c_str())); + + struct logger_list *logger_list; + + ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( + LOG_ID_SYSTEM, O_RDONLY | O_NDELAY, 100, 0))); + + ssize_t max_len = 0; + + for(;;) { + log_msg log_msg; + if (android_logger_list_read(logger_list, &log_msg) <= 0) { + break; + } + + if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) { + continue; + } + + char *data = log_msg.msg() + 1; + + if (strcmp(data, tag)) { + continue; + } + + data += strlen(data) + 1; + + const char *left = data; + const char *right = longString.c_str(); + while (*left && *right && (*left == *right)) { + ++left; + ++right; + } + + if (max_len <= (left - data)) { + max_len = left - data + 1; + } + } + + android_logger_list_close(logger_list); + + EXPECT_LE(LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag), + static_cast<size_t>(max_len)); + + EXPECT_EQ(ret, max_len + static_cast<ssize_t>(sizeof(big_payload_tag))); +} + +TEST(liblog, dual_reader) { + struct logger_list *logger_list1; + + // >25 messages due to liblog.__android_log_buf_print__concurrentXX above. + ASSERT_TRUE(NULL != (logger_list1 = android_logger_list_open( + LOG_ID_MAIN, O_RDONLY | O_NDELAY, 25, 0))); + + struct logger_list *logger_list2; + + if (NULL == (logger_list2 = android_logger_list_open( + LOG_ID_MAIN, O_RDONLY | O_NDELAY, 15, 0))) { + android_logger_list_close(logger_list1); + ASSERT_TRUE(NULL != logger_list2); + } + + int count1 = 0; + bool done1 = false; + int count2 = 0; + bool done2 = false; + + do { + log_msg log_msg; + + if (!done1) { + if (android_logger_list_read(logger_list1, &log_msg) <= 0) { + done1 = true; + } else { + ++count1; + } + } + + if (!done2) { + if (android_logger_list_read(logger_list2, &log_msg) <= 0) { + done2 = true; + } else { + ++count2; + } + } + } while ((!done1) || (!done2)); + + android_logger_list_close(logger_list1); + android_logger_list_close(logger_list2); + + EXPECT_EQ(25, count1); + EXPECT_EQ(15, count2); } TEST(liblog, android_logger_get_) { @@ -308,12 +604,81 @@ TEST(liblog, android_logger_get_) { continue; } struct logger * logger; - ASSERT_EQ(0, NULL == (logger = android_logger_open(logger_list, id))); - ASSERT_EQ(id, android_logger_get_id(logger)); - ASSERT_LT(0, android_logger_get_log_size(logger)); - ASSERT_LT(0, android_logger_get_log_readable_size(logger)); - ASSERT_LT(0, android_logger_get_log_version(logger)); + EXPECT_TRUE(NULL != (logger = android_logger_open(logger_list, id))); + EXPECT_EQ(id, android_logger_get_id(logger)); + EXPECT_LT(0, android_logger_get_log_size(logger)); + EXPECT_LT(0, android_logger_get_log_readable_size(logger)); + EXPECT_LT(0, android_logger_get_log_version(logger)); } android_logger_list_close(logger_list); } + +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)); +} + +TEST(liblog, filterRule) { + static const char tag[] = "random"; + + AndroidLogFormat *p_format = android_log_format_new(); + + android_log_addFilterRule(p_format,"*:i"); + + EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_INFO)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); + android_log_addFilterRule(p_format, "*"); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); + android_log_addFilterRule(p_format, "*:v"); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); + android_log_addFilterRule(p_format, "*:i"); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_INFO)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); + + android_log_addFilterRule(p_format, tag); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); + android_log_addFilterRule(p_format, "random:v"); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); + android_log_addFilterRule(p_format, "random:d"); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0); + android_log_addFilterRule(p_format, "random:w"); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); + + android_log_addFilterRule(p_format, "crap:*"); + EXPECT_TRUE (checkPriForTag(p_format, "crap", ANDROID_LOG_VERBOSE)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, "crap", ANDROID_LOG_VERBOSE) > 0); + + // invalid expression + EXPECT_TRUE (android_log_addFilterRule(p_format, "random:z") < 0); + EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN)); + EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0); + + // Issue #550946 + EXPECT_TRUE(android_log_addFilterString(p_format, " ") == 0); + EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_WARN)); + + // note trailing space + EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:d ") == 0); + EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG)); + + EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:z") < 0); + +#if 0 // bitrot, seek update + char defaultBuffer[512]; + + android_log_formatLogLine(p_format, + defaultBuffer, sizeof(defaultBuffer), 0, ANDROID_LOG_ERROR, 123, + 123, 123, tag, "nofile", strlen("Hello"), "Hello", NULL); + + fprintf(stderr, "%s\n", defaultBuffer); +#endif + + android_log_format_free(p_format); +} |