/liblog/fake_log_device.c
C | 691 lines | 443 code | 90 blank | 158 comment | 118 complexity | 8f4a5683abdbb184871a589f47dc796a MD5 | raw file
- /*
- * Copyright (C) 2008-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.
- */
- /*
- * 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 "fake_log_device.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 */
- #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) {
- ssize_t result = 0;
- const struct iovec* end = iov + iovcnt;
- for (; iov < end; iov++) {
- ssize_t w = write(fd, iov->iov_base, iov->iov_len);
- if (w != (ssize_t) 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:%5d) ", priChar, pid, 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:%5d %c/%-8s ]\n",
- timeBuf, pid, 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;
- const size_t MAX_LINES = ((size_t)~0)/(3*sizeof(struct iovec*));
- struct iovec stackVec[INLINE_VECS];
- struct iovec* vec = stackVec;
- size_t numVecs;
- if (numLines > MAX_LINES)
- numLines = MAX_LINES;
- numVecs = numLines*3; // 3 iovecs per line.
- if (numVecs > INLINE_VECS) {
- vec = (struct iovec*)malloc(sizeof(struct iovec)*numVecs);
- if (vec == NULL) {
- msg = "LOG: write failed, no memory";
- numVecs = 3;
- numLines = 1;
- vec = stackVec;
- }
- }
- /*
- * Fill in the iovec pointers.
- */
- p = msg;
- struct iovec* v = vec;
- int totalLen = 0;
- while (numLines > 0 && 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++;
- }
- numLines -= 1;
- }
-
- /*
- * 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 __unused)
- {
- 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);
- }