diff options
Diffstat (limited to 'liblog/fake_log_device.c')
-rw-r--r-- | liblog/fake_log_device.c | 677 |
1 files changed, 677 insertions, 0 deletions
diff --git a/liblog/fake_log_device.c b/liblog/fake_log_device.c new file mode 100644 index 0000000..d9d67b4 --- /dev/null +++ b/liblog/fake_log_device.c @@ -0,0 +1,677 @@ +/* + * Copyright (C) 2008 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. + */ +/* + * Intercepts log messages intended for the Android log device. + * When running in the context of the simulator, the messages are + * passed on to the underlying (fake) log device. When not in the + * simulator, messages are printed to stderr. + */ +#include "cutils/logd.h" + +#include <stdlib.h> +#include <string.h> +#include <ctype.h> +#include <errno.h> +#include <fcntl.h> + +#ifdef HAVE_PTHREADS +#include <pthread.h> +#endif + +#define kMaxTagLen 16 /* from the long-dead utils/Log.cpp */ + +#define kTagSetSize 16 /* arbitrary */ + +#if 0 +#define TRACE(...) printf("fake_log_device: " __VA_ARGS__) +#else +#define TRACE(...) ((void)0) +#endif + +/* from the long-dead utils/Log.cpp */ +typedef enum { + FORMAT_OFF = 0, + FORMAT_BRIEF, + FORMAT_PROCESS, + FORMAT_TAG, + FORMAT_THREAD, + FORMAT_RAW, + FORMAT_TIME, + FORMAT_THREADTIME, + FORMAT_LONG +} LogFormat; + + +/* + * Log driver state. + */ +typedef struct LogState { + /* the fake fd that's seen by the user */ + int fakeFd; + + /* a printable name for this fake device */ + char *debugName; + + /* nonzero if this is a binary log */ + int isBinary; + + /* global minimum priority */ + int globalMinPriority; + + /* output format */ + LogFormat outputFormat; + + /* tags and priorities */ + struct { + char tag[kMaxTagLen]; + int minPriority; + } tagSet[kTagSetSize]; +} LogState; + + +#ifdef HAVE_PTHREADS +/* + * Locking. Since we're emulating a device, we need to be prepared + * to have multiple callers at the same time. This lock is used + * to both protect the fd list and to prevent LogStates from being + * freed out from under a user. + */ +static pthread_mutex_t fakeLogDeviceLock = PTHREAD_MUTEX_INITIALIZER; + +static void lock() +{ + pthread_mutex_lock(&fakeLogDeviceLock); +} + +static void unlock() +{ + pthread_mutex_unlock(&fakeLogDeviceLock); +} +#else // !HAVE_PTHREADS +#define lock() ((void)0) +#define unlock() ((void)0) +#endif // !HAVE_PTHREADS + + +/* + * File descriptor management. + */ +#define FAKE_FD_BASE 10000 +#define MAX_OPEN_LOGS 16 +static LogState *openLogTable[MAX_OPEN_LOGS]; + +/* + * Allocate an fd and associate a new LogState with it. + * The fd is available via the fakeFd field of the return value. + */ +static LogState *createLogState() +{ + size_t i; + + for (i = 0; i < sizeof(openLogTable); i++) { + if (openLogTable[i] == NULL) { + openLogTable[i] = calloc(1, sizeof(LogState)); + openLogTable[i]->fakeFd = FAKE_FD_BASE + i; + return openLogTable[i]; + } + } + return NULL; +} + +/* + * Translate an fd to a LogState. + */ +static LogState *fdToLogState(int fd) +{ + if (fd >= FAKE_FD_BASE && fd < FAKE_FD_BASE + MAX_OPEN_LOGS) { + return openLogTable[fd - FAKE_FD_BASE]; + } + return NULL; +} + +/* + * Unregister the fake fd and free the memory it pointed to. + */ +static void deleteFakeFd(int fd) +{ + LogState *ls; + + lock(); + + ls = fdToLogState(fd); + if (ls != NULL) { + openLogTable[fd - FAKE_FD_BASE] = NULL; + free(ls->debugName); + free(ls); + } + + unlock(); +} + +/* + * Configure logging based on ANDROID_LOG_TAGS environment variable. We + * need to parse a string that looks like + * + * *:v jdwp:d dalvikvm:d dalvikvm-gc:i dalvikvmi:i + * + * The tag (or '*' for the global level) comes first, followed by a colon + * and a letter indicating the minimum priority level we're expected to log. + * This can be used to reveal or conceal logs with specific tags. + * + * We also want to check ANDROID_PRINTF_LOG to determine how the output + * will look. + */ +static void configureInitialState(const char* pathName, LogState* logState) +{ + static const int kDevLogLen = sizeof("/dev/log/") - 1; + + logState->debugName = strdup(pathName); + + /* identify binary logs */ + if (strcmp(pathName + kDevLogLen, "events") == 0) { + logState->isBinary = 1; + } + + /* global min priority defaults to "info" level */ + logState->globalMinPriority = ANDROID_LOG_INFO; + + /* + * This is based on the the long-dead utils/Log.cpp code. + */ + const char* tags = getenv("ANDROID_LOG_TAGS"); + TRACE("Found ANDROID_LOG_TAGS='%s'\n", tags); + if (tags != NULL) { + int entry = 0; + + while (*tags != '\0') { + char tagName[kMaxTagLen]; + int i, minPrio; + + while (isspace(*tags)) + tags++; + + i = 0; + while (*tags != '\0' && !isspace(*tags) && *tags != ':' && + i < kMaxTagLen) + { + tagName[i++] = *tags++; + } + if (i == kMaxTagLen) { + TRACE("ERROR: env tag too long (%d chars max)\n", kMaxTagLen-1); + return; + } + tagName[i] = '\0'; + + /* default priority, if there's no ":" part; also zero out '*' */ + minPrio = ANDROID_LOG_VERBOSE; + if (tagName[0] == '*' && tagName[1] == '\0') { + minPrio = ANDROID_LOG_DEBUG; + tagName[0] = '\0'; + } + + if (*tags == ':') { + tags++; + if (*tags >= '0' && *tags <= '9') { + if (*tags >= ('0' + ANDROID_LOG_SILENT)) + minPrio = ANDROID_LOG_VERBOSE; + else + minPrio = *tags - '\0'; + } else { + switch (*tags) { + case 'v': minPrio = ANDROID_LOG_VERBOSE; break; + case 'd': minPrio = ANDROID_LOG_DEBUG; break; + case 'i': minPrio = ANDROID_LOG_INFO; break; + case 'w': minPrio = ANDROID_LOG_WARN; break; + case 'e': minPrio = ANDROID_LOG_ERROR; break; + case 'f': minPrio = ANDROID_LOG_FATAL; break; + case 's': minPrio = ANDROID_LOG_SILENT; break; + default: minPrio = ANDROID_LOG_DEFAULT; break; + } + } + + tags++; + if (*tags != '\0' && !isspace(*tags)) { + TRACE("ERROR: garbage in tag env; expected whitespace\n"); + TRACE(" env='%s'\n", tags); + return; + } + } + + if (tagName[0] == 0) { + logState->globalMinPriority = minPrio; + TRACE("+++ global min prio %d\n", logState->globalMinPriority); + } else { + logState->tagSet[entry].minPriority = minPrio; + strcpy(logState->tagSet[entry].tag, tagName); + TRACE("+++ entry %d: %s:%d\n", + entry, + logState->tagSet[entry].tag, + logState->tagSet[entry].minPriority); + entry++; + } + } + } + + + /* + * Taken from the long-dead utils/Log.cpp + */ + const char* fstr = getenv("ANDROID_PRINTF_LOG"); + LogFormat format; + if (fstr == NULL) { + format = FORMAT_BRIEF; + } else { + if (strcmp(fstr, "brief") == 0) + format = FORMAT_BRIEF; + else if (strcmp(fstr, "process") == 0) + format = FORMAT_PROCESS; + else if (strcmp(fstr, "tag") == 0) + format = FORMAT_PROCESS; + else if (strcmp(fstr, "thread") == 0) + format = FORMAT_PROCESS; + else if (strcmp(fstr, "raw") == 0) + format = FORMAT_PROCESS; + else if (strcmp(fstr, "time") == 0) + format = FORMAT_PROCESS; + else if (strcmp(fstr, "long") == 0) + format = FORMAT_PROCESS; + else + format = (LogFormat) atoi(fstr); // really?! + } + + logState->outputFormat = format; +} + +/* + * Return a human-readable string for the priority level. Always returns + * a valid string. + */ +static const char* getPriorityString(int priority) +{ + /* the first character of each string should be unique */ + static const char* priorityStrings[] = { + "Verbose", "Debug", "Info", "Warn", "Error", "Assert" + }; + int idx; + + idx = (int) priority - (int) ANDROID_LOG_VERBOSE; + if (idx < 0 || + idx >= (int) (sizeof(priorityStrings) / sizeof(priorityStrings[0]))) + return "?unknown?"; + return priorityStrings[idx]; +} + +#ifndef HAVE_WRITEV +/* + * Some platforms like WIN32 do not have writev(). + * Make up something to replace it. + */ +static ssize_t fake_writev(int fd, const struct iovec *iov, int iovcnt) { + int result = 0; + struct iovec* end = iov + iovcnt; + for (; iov < end; iov++) { + int w = write(fd, iov->iov_base, iov->iov_len); + if (w != iov->iov_len) { + if (w < 0) + return w; + return result + w; + } + result += w; + } + return result; +} + +#define writev fake_writev +#endif + + +/* + * Write a filtered log message to stderr. + * + * Log format parsing taken from the long-dead utils/Log.cpp. + */ +static void showLog(LogState *state, + int logPrio, const char* tag, const char* msg) +{ +#if defined(HAVE_LOCALTIME_R) + struct tm tmBuf; +#endif + struct tm* ptm; + char timeBuf[32]; + char prefixBuf[128], suffixBuf[128]; + char priChar; + time_t when; + pid_t pid, tid; + + TRACE("LOG %d: %s %s", logPrio, tag, msg); + + priChar = getPriorityString(logPrio)[0]; + when = time(NULL); + pid = tid = getpid(); // find gettid()? + + /* + * Get the current date/time in pretty form + * + * It's often useful when examining a log with "less" to jump to + * a specific point in the file by searching for the date/time stamp. + * For this reason it's very annoying to have regexp meta characters + * in the time stamp. Don't use forward slashes, parenthesis, + * brackets, asterisks, or other special chars here. + */ +#if defined(HAVE_LOCALTIME_R) + ptm = localtime_r(&when, &tmBuf); +#else + ptm = localtime(&when); +#endif + //strftime(timeBuf, sizeof(timeBuf), "%Y-%m-%d %H:%M:%S", ptm); + strftime(timeBuf, sizeof(timeBuf), "%m-%d %H:%M:%S", ptm); + + /* + * Construct a buffer containing the log header and log message. + */ + size_t prefixLen, suffixLen; + + switch (state->outputFormat) { + case FORMAT_TAG: + prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), + "%c/%-8s: ", priChar, tag); + strcpy(suffixBuf, "\n"); suffixLen = 1; + break; + case FORMAT_PROCESS: + prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), + "%c(%5d) ", priChar, pid); + suffixLen = snprintf(suffixBuf, sizeof(suffixBuf), + " (%s)\n", tag); + break; + case FORMAT_THREAD: + prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), + "%c(%5d:%p) ", priChar, pid, (void*)tid); + strcpy(suffixBuf, "\n"); suffixLen = 1; + break; + case FORMAT_RAW: + prefixBuf[0] = 0; prefixLen = 0; + strcpy(suffixBuf, "\n"); suffixLen = 1; + break; + case FORMAT_TIME: + prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), + "%s %-8s\n\t", timeBuf, tag); + strcpy(suffixBuf, "\n"); suffixLen = 1; + break; + case FORMAT_THREADTIME: + prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), + "%s %5d %5d %c %-8s \n\t", timeBuf, pid, tid, priChar, tag); + strcpy(suffixBuf, "\n"); suffixLen = 1; + break; + case FORMAT_LONG: + prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), + "[ %s %5d:%p %c/%-8s ]\n", + timeBuf, pid, (void*)tid, priChar, tag); + strcpy(suffixBuf, "\n\n"); suffixLen = 2; + break; + default: + prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), + "%c/%-8s(%5d): ", priChar, tag, pid); + strcpy(suffixBuf, "\n"); suffixLen = 1; + break; + } + + /* + * Figure out how many lines there will be. + */ + const char* end = msg + strlen(msg); + size_t numLines = 0; + const char* p = msg; + while (p < end) { + if (*p++ == '\n') numLines++; + } + if (p > msg && *(p-1) != '\n') numLines++; + + /* + * Create an array of iovecs large enough to write all of + * the lines with a prefix and a suffix. + */ + const size_t INLINE_VECS = 6; + struct iovec stackVec[INLINE_VECS]; + struct iovec* vec = stackVec; + + numLines *= 3; // 3 iovecs per line. + if (numLines > INLINE_VECS) { + vec = (struct iovec*)malloc(sizeof(struct iovec)*numLines); + if (vec == NULL) { + msg = "LOG: write failed, no memory"; + numLines = 3; + } + } + + /* + * Fill in the iovec pointers. + */ + p = msg; + struct iovec* v = vec; + int totalLen = 0; + while (p < end) { + if (prefixLen > 0) { + v->iov_base = prefixBuf; + v->iov_len = prefixLen; + totalLen += prefixLen; + v++; + } + const char* start = p; + while (p < end && *p != '\n') p++; + if ((p-start) > 0) { + v->iov_base = (void*)start; + v->iov_len = p-start; + totalLen += p-start; + v++; + } + if (*p == '\n') p++; + if (suffixLen > 0) { + v->iov_base = suffixBuf; + v->iov_len = suffixLen; + totalLen += suffixLen; + v++; + } + } + + /* + * Write the entire message to the log file with a single writev() call. + * We need to use this rather than a collection of printf()s on a FILE* + * because of multi-threading and multi-process issues. + * + * If the file was not opened with O_APPEND, this will produce interleaved + * output when called on the same file from multiple processes. + * + * If the file descriptor is actually a network socket, the writev() + * call may return with a partial write. Putting the writev() call in + * a loop can result in interleaved data. This can be alleviated + * somewhat by wrapping the writev call in the Mutex. + */ + + for(;;) { + int cc = writev(fileno(stderr), vec, v-vec); + + if (cc == totalLen) break; + + if (cc < 0) { + if(errno == EINTR) continue; + + /* can't really log the failure; for now, throw out a stderr */ + fprintf(stderr, "+++ LOG: write failed (errno=%d)\n", errno); + break; + } else { + /* shouldn't happen when writing to file or tty */ + fprintf(stderr, "+++ LOG: write partial (%d of %d)\n", cc, totalLen); + break; + } + } + + /* if we allocated storage for the iovecs, free it */ + if (vec != stackVec) + free(vec); +} + + +/* + * Receive a log message. We happen to know that "vector" has three parts: + * + * priority (1 byte) + * tag (N bytes -- null-terminated ASCII string) + * message (N bytes -- null-terminated ASCII string) + */ +static ssize_t logWritev(int fd, const struct iovec* vector, int count) +{ + LogState* state; + + /* Make sure that no-one frees the LogState while we're using it. + * Also guarantees that only one thread is in showLog() at a given + * time (if it matters). + */ + lock(); + + state = fdToLogState(fd); + if (state == NULL) { + errno = EBADF; + goto error; + } + + if (state->isBinary) { + TRACE("%s: ignoring binary log\n", state->debugName); + goto bail; + } + + if (count != 3) { + TRACE("%s: writevLog with count=%d not expected\n", + state->debugName, count); + goto error; + } + + /* pull out the three fields */ + int logPrio = *(const char*)vector[0].iov_base; + const char* tag = (const char*) vector[1].iov_base; + const char* msg = (const char*) vector[2].iov_base; + + /* see if this log tag is configured */ + int i; + int minPrio = state->globalMinPriority; + for (i = 0; i < kTagSetSize; i++) { + if (state->tagSet[i].minPriority == ANDROID_LOG_UNKNOWN) + break; /* reached end of configured values */ + + if (strcmp(state->tagSet[i].tag, tag) == 0) { + //TRACE("MATCH tag '%s'\n", tag); + minPrio = state->tagSet[i].minPriority; + break; + } + } + + if (logPrio >= minPrio) { + showLog(state, logPrio, tag, msg); + } else { + //TRACE("+++ NOLOG(%d): %s %s", logPrio, tag, msg); + } + +bail: + unlock(); + return vector[0].iov_len + vector[1].iov_len + vector[2].iov_len; +error: + unlock(); + return -1; +} + +/* + * Free up our state and close the fake descriptor. + */ +static int logClose(int fd) +{ + deleteFakeFd(fd); + return 0; +} + +/* + * Open a log output device and return a fake fd. + */ +static int logOpen(const char* pathName, int flags) +{ + LogState *logState; + int fd = -1; + + lock(); + + logState = createLogState(); + if (logState != NULL) { + configureInitialState(pathName, logState); + fd = logState->fakeFd; + } else { + errno = ENFILE; + } + + unlock(); + + return fd; +} + + +/* + * Runtime redirection. If this binary is running in the simulator, + * just pass log messages to the emulated device. If it's running + * outside of the simulator, write the log messages to stderr. + */ + +static int (*redirectOpen)(const char *pathName, int flags) = NULL; +static int (*redirectClose)(int fd) = NULL; +static ssize_t (*redirectWritev)(int fd, const struct iovec* vector, int count) + = NULL; + +static void setRedirects() +{ + const char *ws; + + /* Wrapsim sets this environment variable on children that it's + * created using its LD_PRELOAD wrapper. + */ + ws = getenv("ANDROID_WRAPSIM"); + if (ws != NULL && strcmp(ws, "1") == 0) { + /* We're running inside wrapsim, so we can just write to the device. */ + redirectOpen = (int (*)(const char *pathName, int flags))open; + redirectClose = close; + redirectWritev = writev; + } else { + /* There's no device to delegate to; handle the logging ourselves. */ + redirectOpen = logOpen; + redirectClose = logClose; + redirectWritev = logWritev; + } +} + +int fakeLogOpen(const char *pathName, int flags) +{ + if (redirectOpen == NULL) { + setRedirects(); + } + return redirectOpen(pathName, flags); +} + +int fakeLogClose(int fd) +{ + /* Assume that open() was called first. */ + return redirectClose(fd); +} + +ssize_t fakeLogWritev(int fd, const struct iovec* vector, int count) +{ + /* Assume that open() was called first. */ + return redirectWritev(fd, vector, count); +} |