diff options
-rw-r--r-- | logwrapper/Android.mk | 2 | ||||
-rw-r--r-- | logwrapper/include/logwrap/logwrap.h | 29 | ||||
-rw-r--r-- | logwrapper/logwrap.c | 341 | ||||
-rw-r--r-- | logwrapper/logwrapper.c | 45 |
4 files changed, 371 insertions, 46 deletions
diff --git a/logwrapper/Android.mk b/logwrapper/Android.mk index b4b6b29..917bf37 100644 --- a/logwrapper/Android.mk +++ b/logwrapper/Android.mk @@ -30,5 +30,5 @@ include $(BUILD_SHARED_LIBRARY) include $(CLEAR_VARS) LOCAL_SRC_FILES:= logwrapper.c LOCAL_MODULE := logwrapper -LOCAL_STATIC_LIBRARIES := liblog liblogwrap +LOCAL_STATIC_LIBRARIES := liblog liblogwrap libcutils include $(BUILD_EXECUTABLE) diff --git a/logwrapper/include/logwrap/logwrap.h b/logwrapper/include/logwrap/logwrap.h index 2be8736..8087f0a 100644 --- a/logwrapper/include/logwrap/logwrap.h +++ b/logwrapper/include/logwrap/logwrap.h @@ -43,7 +43,12 @@ __BEGIN_DECLS * SIGQUIT while logwrap is running. This may force the end-user to * send a signal twice to signal the caller (once for the child, and * once for the caller) - * logwrap: when true, log messages from the child + * log_target: Specify where to log the output of the child, either LOG_NONE, + * LOG_ALOG (for the Android system log) or LOG_KLOG (for the kernel + * log). + * abbreviated: If true, capture up to the first 100 lines and last 4K of + * output from the child. The abbreviated output is not dumped to + * the specified log until the child has exited. * * Return value: * 0 when logwrap successfully run the child process and captured its status @@ -52,8 +57,26 @@ __BEGIN_DECLS * the return value of the child if it exited properly and status is NULL * */ -int android_fork_execvp(int argc, char* argv[], int *status, bool ignore_int_quit, - bool logwrap); + +/* Values for the log_target parameter android_fork_exec_ext() */ +#define LOG_NONE 0 +#define LOG_ALOG 1 +#define LOG_KLOG 2 + +int android_fork_execvp_ext(int argc, char* argv[], int *status, bool ignore_int_quit, + int log_target, bool abbreviated); + +/* Similar to above, except abbreviated logging is not available, and if logwrap + * is true, logging is to the Android system log, and if false, there is no + * logging. + */ +static inline int android_fork_execvp(int argc, char* argv[], int *status, + bool ignore_int_quit, bool logwrap) +{ + return android_fork_execvp_ext(argc, argv, status, ignore_int_quit, + (logwrap ? LOG_ALOG : LOG_NONE), false); +} + __END_DECLS diff --git a/logwrapper/logwrap.c b/logwrapper/logwrap.c index bf91977..01cc9a1 100644 --- a/logwrapper/logwrap.c +++ b/logwrapper/logwrap.c @@ -31,8 +31,10 @@ #include <logwrap/logwrap.h> #include "private/android_filesystem_config.h" #include "cutils/log.h" +#include <cutils/klog.h> #define ARRAY_SIZE(x) (sizeof(x) / sizeof(*(x))) +#define MIN(a,b) (((a)<(b))?(a):(b)) static pthread_mutex_t fd_mutex = PTHREAD_MUTEX_INITIALIZER; @@ -48,8 +50,247 @@ do { \ _exit(-1); \ } while(0) -static int parent(const char *tag, int parent_read, pid_t pid, int *chld_sts, - bool logwrap) { +#define MAX_KLOG_TAG 16 + +/* This is a simple buffer that holds up to the first beginning_buf->buf_size + * bytes of output from a command. + */ +#define BEGINNING_BUF_SIZE 0x1000 +struct beginning_buf { + char *buf; + size_t alloc_len; + /* buf_size is the usable space, which is one less than the allocated size */ + size_t buf_size; + size_t used_len; +}; + +/* This is a circular buf that holds up to the last ending_buf->buf_size bytes + * of output from a command after the first beginning_buf->buf_size bytes + * (which are held in beginning_buf above). + */ +#define ENDING_BUF_SIZE 0x1000 +struct ending_buf { + char *buf; + ssize_t alloc_len; + /* buf_size is the usable space, which is one less than the allocated size */ + ssize_t buf_size; + ssize_t used_len; + /* read and write offsets into the circular buffer */ + int read; + int write; +}; + + /* A structure to hold all the abbreviated buf data */ +struct abbr_buf { + struct beginning_buf b_buf; + struct ending_buf e_buf; + int beginning_buf_full; +}; + +/* Collect all the various bits of info needed for logging in one place. */ +struct log_info { + int log_target; + char klog_fmt[MAX_KLOG_TAG * 2]; + char *btag; + bool abbreviated; + struct abbr_buf a_buf; +}; + +/* Forware declaration */ +static void add_line_to_abbr_buf(struct abbr_buf *a_buf, char *linebuf, int linelen); + +/* Return 0 on success, and 1 when full */ +static int add_line_to_linear_buf(struct beginning_buf *b_buf, + char *line, ssize_t line_len) +{ + size_t new_len; + char *new_buf; + int full = 0; + + if ((line_len + b_buf->used_len) > b_buf->buf_size) { + full = 1; + } else { + /* Add to the end of the buf */ + memcpy(b_buf->buf + b_buf->used_len, line, line_len); + b_buf->used_len += line_len; + } + + return full; +} + +static void add_line_to_circular_buf(struct ending_buf *e_buf, + char *line, ssize_t line_len) +{ + ssize_t free_len; + ssize_t needed_space; + char *new_buf; + int cnt; + + if (e_buf->buf == NULL) { + return; + } + + if (line_len > e_buf->buf_size) { + return; + } + + free_len = e_buf->buf_size - e_buf->used_len; + + if (line_len > free_len) { + /* remove oldest entries at read, and move read to make + * room for the new string */ + needed_space = line_len - free_len; + e_buf->read = (e_buf->read + needed_space) % e_buf->buf_size; + e_buf->used_len -= needed_space; + } + + /* Copy the line into the circular buffer, dealing with possible + * wraparound. + */ + cnt = MIN(line_len, e_buf->buf_size - e_buf->write); + memcpy(e_buf->buf + e_buf->write, line, cnt); + if (cnt < line_len) { + memcpy(e_buf->buf, line + cnt, line_len - cnt); + } + e_buf->used_len += line_len; + e_buf->write = (e_buf->write + line_len) % e_buf->buf_size; +} + +/* Log directly to the specified log */ +static void do_log_line(struct log_info *log_info, char *line) { + if (log_info->log_target == LOG_KLOG) { + klog_write(6, log_info->klog_fmt, line); + } else if (log_info->log_target == LOG_ALOG) { + ALOG(LOG_INFO, log_info->btag, "%s", line); + } +} + +/* Log to either the abbreviated buf, or directly to the specified log + * via do_log_line() above. + */ +static void log_line(struct log_info *log_info, char *line, int len) { + if (log_info->abbreviated) { + add_line_to_abbr_buf(&log_info->a_buf, line, len); + } else { + do_log_line(log_info, line); + } +} + +/* + * The kernel will take a maximum of 1024 bytes in any single write to + * the kernel logging device file, so find and print each line one at + * a time. The allocated size for buf should be at least 1 byte larger + * than buf_size (the usable size of the buffer) to make sure there is + * room to temporarily stuff a null byte to terminate a line for logging. + */ +static void print_buf_lines(struct log_info *log_info, char *buf, int buf_size) +{ + char *line_start; + char c; + int line_len; + int i; + + line_start = buf; + for (i = 0; i < buf_size; i++) { + if (*(buf + i) == '\n') { + /* Found a line ending, print the line and compute new line_start */ + /* Save the next char and replace with \0 */ + c = *(buf + i + 1); + *(buf + i + 1) = '\0'; + do_log_line(log_info, line_start); + /* Restore the saved char */ + *(buf + i + 1) = c; + line_start = buf + i + 1; + } else if (*(buf + i) == '\0') { + /* The end of the buffer, print the last bit */ + do_log_line(log_info, line_start); + break; + } + } + /* If the buffer was completely full, and didn't end with a newline, just + * ignore the partial last line. + */ +} + +static void init_abbr_buf(struct abbr_buf *a_buf) { + char *new_buf; + + memset(a_buf, 0, sizeof(struct abbr_buf)); + new_buf = malloc(BEGINNING_BUF_SIZE); + if (new_buf) { + a_buf->b_buf.buf = new_buf; + a_buf->b_buf.alloc_len = BEGINNING_BUF_SIZE; + a_buf->b_buf.buf_size = BEGINNING_BUF_SIZE - 1; + } + new_buf = malloc(ENDING_BUF_SIZE); + if (new_buf) { + a_buf->e_buf.buf = new_buf; + a_buf->e_buf.alloc_len = ENDING_BUF_SIZE; + a_buf->e_buf.buf_size = ENDING_BUF_SIZE - 1; + } +} + +static void free_abbr_buf(struct abbr_buf *a_buf) { + free(a_buf->b_buf.buf); + free(a_buf->e_buf.buf); +} + +static void add_line_to_abbr_buf(struct abbr_buf *a_buf, char *linebuf, int linelen) { + if (!a_buf->beginning_buf_full) { + a_buf->beginning_buf_full = + add_line_to_linear_buf(&a_buf->b_buf, linebuf, linelen); + } + if (a_buf->beginning_buf_full) { + add_line_to_circular_buf(&a_buf->e_buf, linebuf, linelen); + } +} + +static void print_abbr_buf(struct log_info *log_info) { + struct abbr_buf *a_buf = &log_info->a_buf; + + /* Add the abbreviated output to the kernel log */ + if (a_buf->b_buf.alloc_len) { + print_buf_lines(log_info, a_buf->b_buf.buf, a_buf->b_buf.used_len); + } + + /* Print an ellipsis to indicate that the buffer has wrapped or + * is full, and some data was not logged. + */ + if (a_buf->e_buf.used_len == a_buf->e_buf.buf_size) { + do_log_line(log_info, "...\n"); + } + + if (a_buf->e_buf.used_len == 0) { + return; + } + + /* Simplest way to print the circular buffer is allocate a second buf + * of the same size, and memcpy it so it's a simple linear buffer, + * and then cal print_buf_lines on it */ + if (a_buf->e_buf.read < a_buf->e_buf.write) { + /* no wrap around, just print it */ + print_buf_lines(log_info, a_buf->e_buf.buf + a_buf->e_buf.read, + a_buf->e_buf.used_len); + } else { + /* The circular buffer will always have at least 1 byte unused, + * so by allocating alloc_len here we will have at least + * 1 byte of space available as required by print_buf_lines(). + */ + char * nbuf = malloc(a_buf->e_buf.alloc_len); + if (!nbuf) { + return; + } + int first_chunk_len = a_buf->e_buf.buf_size - a_buf->e_buf.read; + memcpy(nbuf, a_buf->e_buf.buf + a_buf->e_buf.read, first_chunk_len); + /* copy second chunk */ + memcpy(nbuf + first_chunk_len, a_buf->e_buf.buf, a_buf->e_buf.write); + print_buf_lines(log_info, nbuf, first_chunk_len + a_buf->e_buf.write); + free(nbuf); + } +} + +static int parent(const char *tag, int parent_read, pid_t pid, + int *chld_sts, int log_target, bool abbreviated) { int status = 0; char buffer[4096]; struct pollfd poll_fds[] = { @@ -60,13 +301,32 @@ static int parent(const char *tag, int parent_read, pid_t pid, int *chld_sts, }; int rc = 0; + struct log_info log_info; + int a = 0; // start index of unprocessed data int b = 0; // end index of unprocessed data int sz; bool found_child = false; + char tmpbuf[256]; - char *btag = basename(tag); - if (!btag) btag = (char*) tag; + log_info.log_target = log_target; + log_info.abbreviated = abbreviated; + log_info.btag = basename(tag); + if (!log_info.btag) { + log_info.btag = (char*) tag; + } + + if (abbreviated && (log_target == LOG_NONE)) { + abbreviated = 0; + } + if (abbreviated) { + init_abbr_buf(&log_info.a_buf); + } + + if (log_target == LOG_KLOG) { + snprintf(log_info.klog_fmt, sizeof(log_info.klog_fmt), + "<6>%.*s: %%s", MAX_KLOG_TAG, log_info.btag); + } while (!found_child) { if (TEMP_FAILURE_RETRY(poll(poll_fds, ARRAY_SIZE(poll_fds), -1)) < 0) { @@ -82,11 +342,21 @@ static int parent(const char *tag, int parent_read, pid_t pid, int *chld_sts, // Log one line at a time for (b = 0; b < sz; b++) { if (buffer[b] == '\r') { - buffer[b] = '\0'; + if (abbreviated) { + /* The abbreviated logging code uses newline as + * the line separator. Lucikly, the pty layer + * helpfully cooks the output of the command + * being run and inserts a CR before NL. So + * I just change it to NL here when doing + * abbreviated logging. + */ + buffer[b] = '\n'; + } else { + buffer[b] = '\0'; + } } else if (buffer[b] == '\n') { buffer[b] = '\0'; - if (logwrap) - ALOG(LOG_INFO, btag, "%s", &buffer[a]); + log_line(&log_info, &buffer[a], b - a); a = b + 1; } } @@ -94,8 +364,7 @@ static int parent(const char *tag, int parent_read, pid_t pid, int *chld_sts, if (a == 0 && b == sizeof(buffer) - 1) { // buffer is full, flush buffer[b] = '\0'; - if (logwrap) - ALOG(LOG_INFO, btag, "%s", &buffer[a]); + log_line(&log_info, &buffer[a], b - a); b = 0; } else if (a != b) { // Keep left-overs @@ -132,32 +401,44 @@ static int parent(const char *tag, int parent_read, pid_t pid, int *chld_sts, rc = -ECHILD; } - if (logwrap) { - // Flush remaining data - if (a != b) { - buffer[b] = '\0'; - ALOG(LOG_INFO, btag, "%s", &buffer[a]); + // Flush remaining data + if (a != b) { + buffer[b] = '\0'; + log_line(&log_info, &buffer[a], b - a); + } + + /* All the output has been processed, time to dump the abbreviated output */ + if (abbreviated) { + print_abbr_buf(&log_info); + } + + if (WIFEXITED(status)) { + if (WEXITSTATUS(status)) { + snprintf(tmpbuf, sizeof(tmpbuf), + "%s terminated by exit(%d)\n", log_info.btag, WEXITSTATUS(status)); + do_log_line(&log_info, tmpbuf); } - if (WIFEXITED(status)) { - if (WEXITSTATUS(status)) - ALOG(LOG_INFO, "logwrapper", "%s terminated by exit(%d)", btag, - WEXITSTATUS(status)); - } else { - if (WIFSIGNALED(status)) - ALOG(LOG_INFO, "logwrapper", "%s terminated by signal %d", btag, - WTERMSIG(status)); - else if (WIFSTOPPED(status)) - ALOG(LOG_INFO, "logwrapper", "%s stopped by signal %d", btag, - WSTOPSIG(status)); + } else { + if (WIFSIGNALED(status)) { + snprintf(tmpbuf, sizeof(tmpbuf), + "%s terminated by signal %d\n", log_info.btag, WTERMSIG(status)); + do_log_line(&log_info, tmpbuf); + } else if (WIFSTOPPED(status)) { + snprintf(tmpbuf, sizeof(tmpbuf), + "%s stopped by signal %d\n", log_info.btag, WSTOPSIG(status)); + do_log_line(&log_info, tmpbuf); } } err_waitpid: err_poll: + if (abbreviated) { + free_abbr_buf(&log_info.a_buf); + } return rc; } -static void child(int argc, char* argv[], bool logwrap) { +static void child(int argc, char* argv[]) { // create null terminated argv_child array char* argv_child[argc + 1]; memcpy(argv_child, argv, argc * sizeof(char *)); @@ -169,8 +450,8 @@ static void child(int argc, char* argv[], bool logwrap) { } } -int android_fork_execvp(int argc, char* argv[], int *status, bool ignore_int_quit, - bool logwrap) { +int android_fork_execvp_ext(int argc, char* argv[], int *status, bool ignore_int_quit, + int log_target, bool abbreviated) { pid_t pid; int parent_ptty; int child_ptty; @@ -230,7 +511,7 @@ int android_fork_execvp(int argc, char* argv[], int *status, bool ignore_int_qui dup2(child_ptty, 2); close(child_ptty); - child(argc, argv, logwrap); + child(argc, argv); } else { close(child_ptty); if (ignore_int_quit) { @@ -242,7 +523,7 @@ int android_fork_execvp(int argc, char* argv[], int *status, bool ignore_int_qui sigaction(SIGQUIT, &ignact, &quitact); } - rc = parent(argv[0], parent_ptty, pid, status, logwrap); + rc = parent(argv[0], parent_ptty, pid, status, log_target, abbreviated); } if (ignore_int_quit) { diff --git a/logwrapper/logwrapper.c b/logwrapper/logwrapper.c index ed71a29..d1c6240 100644 --- a/logwrapper/logwrapper.c +++ b/logwrapper/logwrapper.c @@ -17,8 +17,10 @@ #include <stdio.h> #include <stdlib.h> #include <sys/wait.h> +#include <unistd.h> #include <logwrap/logwrap.h> +#include <cutils/klog.h> #include "cutils/log.h" @@ -30,36 +32,55 @@ void fatal(const char *msg) { void usage() { fatal( - "Usage: logwrapper [-d] BINARY [ARGS ...]\n" + "Usage: logwrapper [-a] [-d] [-k] BINARY [ARGS ...]\n" "\n" "Forks and executes BINARY ARGS, redirecting stdout and stderr to\n" "the Android logging system. Tag is set to BINARY, priority is\n" "always LOG_INFO.\n" "\n" + "-a: Causes logwrapper to do abbreviated logging.\n" + " This logs up to the first 4K and last 4K of the command\n" + " being run, and logs the output when the command exits\n" "-d: Causes logwrapper to SIGSEGV when BINARY terminates\n" - " fault address is set to the status of wait()\n"); + " fault address is set to the status of wait()\n" + "-k: Causes logwrapper to log to the kernel log instead of\n" + " the Android system log\n"); } int main(int argc, char* argv[]) { int seg_fault_on_exit = 0; + int log_target = LOG_ALOG; + bool abbreviated = false; + int ch; int status = 0xAAAA; int rc; - if (argc < 2) { - usage(); - } - - if (strncmp(argv[1], "-d", 2) == 0) { - seg_fault_on_exit = 1; - argc--; - argv++; + while ((ch = getopt(argc, argv, "adk")) != -1) { + switch (ch) { + case 'a': + abbreviated = true; + break; + case 'd': + seg_fault_on_exit = 1; + break; + case 'k': + log_target = LOG_KLOG; + klog_set_level(6); + break; + case '?': + default: + usage(); + } } + argc -= optind; + argv += optind; - if (argc < 2) { + if (argc < 1) { usage(); } - rc = android_fork_execvp(argc - 1, &argv[1], &status, true, true); + rc = android_fork_execvp_ext(argc, &argv[0], &status, true, + log_target, abbreviated); if (!rc) { if (WIFEXITED(status)) rc = WEXITSTATUS(status); |