（Android系统）android log机制浅析

在android下面debug，最主要的方式就是用logcat抓log了，我们可能有尝试过使用printf来打印，当然结果是不行的，这里有时间就看了一下android平台下log的flow，在此做个笔记以作记录


我们一般使用ALOGD来打印log，所以这里就跟一下ALOGD的flow
system/core/include/log/log.h

system/core/include/log/log.h

#ifndef ALOGD                                                                                                                      
#define ALOGD(...) ((void)ALOG(LOG_DEBUG, LOG_TAG, __VA_ARGS__))
#endif


#ifndef ALOG
#define ALOG(priority, tag, ...)     LOG_PRI(ANDROID_##priority, tag, __VA_ARGS__)
#endif


#ifndef LOG_PRI                                                                                                                    
#define LOG_PRI(priority, tag, ...)     android_printLog(priority, tag, __VA_ARGS__)
#endif

#define android_printLog(prio, tag, fmt...) \                                                                                      
    __android_log_print(prio, tag, fmt)

这里有发现ALOGD其实是一系列宏，最终会调用到 __android_log_print(prio, tag, fmt)，这个函数带三个参数：
1，优先级，这个就是我们平时说的log level，ALOGD的log level是LOG_DEBUG；
2，tag，这个就是我们在code里面指定的LOG_TAG
3，__VA_ARGS__，这个就是我们常见的格式化输入了，也就是说我们ALOGD带的参数可以使用格式化的格式


关于__android_log_print的具体实现如下：
system/core/liblog/logd_write.c

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);
}

这里可以看到格式化的输入被转化成buf的字符数组了，然后buf作为第三个参数调用__android_log_write


关于__android_log_write的具体实现如下：

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;
    }


    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);
}

可以看到priority，tag，msg三个参数分别填充到了iovec的struct中，
iovec是io vetor，与readv和writev相关的一种struct，readv和readv是高级I/O，这里不做深入解释，
大家只需要知道调用者传进来的参数按照固定的格式填充到了iovec中，最后调用write_to_log(log_id, vec, 3);


这里大家可以看一下write_to_log的具体实现：

static int (*write_to_log)(log_id_t, struct iovec *vec, size_t nr) = __write_to_log_init;

可以发现write_to_log是一个函数指针，初始化为__write_to_log_init


但是write_to_log在init的时候被赋值成__write_to_log_kernel

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;

我们接下来看一下__write_to_log_kernel的具体实现

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) {
        log_fd = log_fds[(int)log_id];
    } else {
        return EBADF;
    }


    do {
        ret = log_writev(log_fd, vec, nr);
    } while (ret < 0 && errno == EINTR);


    return ret;
}

可以看到是调用了log_writev(log_fd, vec, nr)，这里的三个参数分别是：
1，log_fd，也就是我们ALOGD产生的log所需要写入的fd，这里是/dev/log/main，/dev/log/radio/,dev/log/event,/dev/log/system等文件
2，vec，这个就是包含了priority，tag，msg等信息的iovec，专门供readv和wirtev使用的struct
3：nr，这里应该是vec结构体数组的个数，这里是3个，分别填充了priority，tag，msg

#if FAKE_LOG_DEVICE
// This will be defined when building for the host.
#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

看到了吧，这里就是用writev把vec里面填充的内容按固定格式写到log_fd对应的路径了，至此ALOGD所要打印的msg被写入到了/dev/log/main等路径了



接下来我们看一下logcat的flow，为什么在终端输入logcat之后，log信息就会被打印到终端之上
首先我们需要解释下，为什么printf无法打印信息到终端：
system/core/init/init.c

static void open_console()
{
    int fd;
    if ((fd = open(console_name, O_RDWR)) < 0) {
        fd = open("/dev/null", O_RDWR);
    }
    ioctl(fd, TIOCSCTTY, 0);
    dup2(fd, 0);
    dup2(fd, 1);
    dup2(fd, 2);
    close(fd);
}

原来init进程在启动的时候把0,1,2等三个fd都定向到了/dev/null，所以我们printf输出给stdout（也就是fd 1）都丢给了/dev/null，这样子也就不会有信息了


android官方给出的解释如下(system/core/init/readme.txt)：
By default, programs executed by init will drop stdout and stderr into
/dev/null. To help with debugging, you can execute your program via the
Andoird program logwrapper. This will redirect stdout/stderr into the
Android logging system (accessed via logcat).




system/core/logcat/logcat.cpp
先从logcat的main函数走起，首先会遇到一个重要的地方

if (!devices) {                                                                                                                
	devices = new log_device_t(strdup("/dev/"LOGGER_LOG_MAIN), false, 'm');
	android::g_devCount = 1;
	int accessmode =
			  (mode & O_RDONLY) ? R_OK : 0
			| (mode & O_WRONLY) ? W_OK : 0;
	// only add this if it's available
	if (0 == access("/dev/"LOGGER_LOG_SYSTEM, accessmode)) {
		devices->next = new log_device_t(strdup("/dev/"LOGGER_LOG_SYSTEM), false, 's');
		android::g_devCount++;
	}
}

这里我们有发现logcat使用/dev/log/main和/dev/log/system两个路径作为device，这里g_devCount的值是2


接下来会设置output的路径，这里很重要，直接关联到log的输出，我们发现可以输出到STDOUT_FILENO，也可以是系统指定的参数，这个是-f所指定的，关于-f的作用，可以使用help文档确认一下

static void setupOutput()                                                                                                          
{


    if (g_outputFileName == NULL) {
        g_outFD = STDOUT_FILENO;


    } else {
        struct stat statbuf;


        g_outFD = openLogFile (g_outputFileName);


        if (g_outFD < 0) {
            perror ("couldn't open output file");
            exit(-1);
        }


        fstat(g_outFD, &statbuf);


        g_outByteCount = statbuf.st_size;
    }
}

一般我们直接使用logcat的时候，g_outFD所对应的输出设备就是我们的终端，这也就是为什么logcat可以把log打印到终端


最后是一个很重要的地方，这里用select的机制去查询/dev/log/main和/dev/log/system两个路径是否有log信息可以打印，
如果有的话就打印到终端，如果没有的话就sleep 5ms，这里的时间是select函数的最后一个参数指定的

static void readLogLines(log_device_t* devices)
{
    log_device_t* dev;
    int max = 0;
    int ret;
    int queued_lines = 0;
    bool sleep = false;


    int result;
    fd_set readset;


    for (dev=devices; dev; dev = dev->next) {
        if (dev->fd > max) {
            max = dev->fd;
        }
    }


    while (1) {
        do {
            timeval timeout = { 0, 5000 /* 5ms */ }; // If we oversleep it's ok, i.e. ignore EINTR.
            FD_ZERO(&readset);
            for (dev=devices; dev; dev = dev->next) {
                FD_SET(dev->fd, &readset);
            }
            result = select(max + 1, &readset, NULL, NULL, sleep ? NULL : &timeout);
        } while (result == -1 && errno == EINTR);


        if (result >= 0) {
            for (dev=devices; dev; dev = dev->next) {
                if (FD_ISSET(dev->fd, &readset)) {
                    queued_entry_t* entry = new queued_entry_t();
                    /* NOTE: driver guarantees we read exactly one full entry */
                    ret = read(dev->fd, entry->buf, LOGGER_ENTRY_MAX_LEN);
                    if (ret < 0) {
                        if (errno == EINTR) {
                            delete entry;
                            goto next;
                        }
                        if (errno == EAGAIN) {
                            delete entry;
                            break;
                        }
                        perror("logcat read");
                        exit(EXIT_FAILURE);
                    }
                    else if (!ret) {
                        fprintf(stderr, "read: Unexpected EOF!\n");
                        exit(EXIT_FAILURE);
                    }
                    else if (entry->entry.len != ret - sizeof(struct logger_entry)) {
                        fprintf(stderr, "read: unexpected length. Expected %d, got %d\n",
                                entry->entry.len, ret - sizeof(struct logger_entry));
                        exit(EXIT_FAILURE);


                    entry->entry.msg[entry->entry.len] = '\0';


                    dev->enqueue(entry);
                    ++queued_lines;
                }
            }


            if (result == 0) {
                // we did our short timeout trick and there's nothing new
                // print everything we have and wait for more data
                sleep = true;
                while (true) {
                    chooseFirst(devices, &dev);
                    if (dev == NULL) {
                        break;
                    }
                    if (g_tail_lines == 0 || queued_lines <= g_tail_lines) {
                        printNextEntry(dev);
                    } else {
                        skipNextEntry(dev);
                    }
                    --queued_lines;
                }


                // the caller requested to just dump the log and exit
                if (g_nonblock) {
                    return;
                }
            } else {
                // print all that aren't the last in their list
                sleep = false;
                while (g_tail_lines == 0 || queued_lines > g_tail_lines) {
                    chooseFirst(devices, &dev);
                    if (dev == NULL || dev->queue->next == NULL) {
                        break;
                    }
                    if (g_tail_lines == 0) {
                        printNextEntry(dev);
                    } else {
                        skipNextEntry(dev);
                    }
                    --queued_lines;
                }
            }
        }
next:
        ;
    }
}

可以看到在result>0的时候，也就是select在判断/dev/log/main和/dev/log/system两个路径中有任意一个是readable的话，就去执行如下函数

static void printNextEntry(log_device_t* dev) {                                                                                    
    maybePrintStart(dev);
    if (g_printBinary) {
        printBinary(&dev->queue->entry);
    } else {
        processBuffer(dev, &dev->queue->entry);
    }
    skipNextEntry(dev);
}


static void skipNextEntry(log_device_t* dev) {
    maybePrintStart(dev);
    queued_entry_t* entry = dev->queue;
    dev->queue = entry->next;
    delete entry;
}

这里就会把/dev/log/main或者/dev/log/system中读到的信息（也就是前面用ALOGD存入的信息）打印到g_outFD所对应的设备上，默认的话就是终端

static void maybePrintStart(log_device_t* dev) {
    if (!dev->printed) {
        dev->printed = true;
        if (g_devCount > 1 && !g_printBinary) {
            char buf[1024];
            snprintf(buf, sizeof(buf), "--------- beginning of %s\n", dev->device);
            if (write(g_outFD, buf, strlen(buf)) < 0) {
                perror("output error");
                exit(-1);
            }
        }
    }
}

到这里logcat的整个流程已经完毕，希望对大家有所帮助

（Android系统）android log机制浅析,,5-wow.com