openkylin
/
platform_system_core
mirror of https://gitee.com/openkylin/platform_system_core.git
9
0
Fork 0
Code Issues Projects Releases Wiki Activity

Merge "logwrapper: Add ability to log to kernel log" into jb-mr2-dev

This commit is contained in:
Ken Sumrall 2013-04-15 17:33:44 +00:00 committed by Android (Google) Code Review
parent 774814d194 96e11b5bc4
commit 1f75eb1eae
4 changed files with 373 additions and 48 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
logwrapper/Android.mk
View File

@ -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)

29
logwrapper/include/logwrap/logwrap.h
View File

@ -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

341
logwrapper/logwrap.c
View File

@ -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) {

49
logwrapper/logwrapper.c
View File

@ -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) {
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 < 1) {
usage();
}
if (strncmp(argv[1], "-d", 2) == 0) {
seg_fault_on_exit = 1;
argc--;
argv++;
}
if (argc < 2) {
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);