在分析Android7.0 init程序一文中提到，在init程序中是通過klog來輸出log資訊的，但是由於log的級別不同可能導致有些新增的log無法輸出來。在init .cpp的main函式中初始化klog。

    klog_init();          //初始化klog
    klog_set_level(KLOG_NOTICE_LEVEL);   //設定klog的級別為NOTICE

system/core/libcutils/klog.c

void klog_init(void) {
    if (klog_fd >= 0) return; /* Already initialized */      //klog_fd預設值為-1，如果大於等於1表示klog已經初始化過，返回

    klog_fd = open("/dev/kmsg", O_WRONLY | O_CLOEXEC);   //開啟/dev/kmsg檔案，獲得檔案描述符
    if (klog_fd >= 0) {                      //大於等於0表示，開啟成功，init程序的log都會輸出到kernel log中
        return;  
    }

    static const char* name = "/dev/__kmsg__"; 
    if (mknod(name, S_IFCHR | 0600, (1 << 8) | 11) == 0) {   //如果上面沒有開啟成功，建立/dev/_kmsg_檔案
        klog_fd = open(name, O_WRONLY | O_CLOEXEC);      //開啟檔案，獲取檔案描述符
        unlink(name);
    }
}
 

void klog_set_level(int level) {
    klog_level = level;                  //將設定的level賦值給klog_level
}

在init.cpp通過NOTICE函式輸出log資訊。但是INFO函式就輸不出log，下面我們看一下具體原因。

    NOTICE("init %s started!\n", is_first_stage ? "first stage" : "second stage");

在system/core/init/log.h標頭檔案中對NOTICE，INFO等函式進行定義

#define ERROR(x...)   init_klog_write(KLOG_ERROR_LEVEL, x)
#define WARNING(x...) init_klog_write(KLOG_WARNING_LEVEL, x)
#define NOTICE(x...)  init_klog_write(KLOG_NOTICE_LEVEL, x)
#define INFO(x...)    init_klog_write(KLOG_INFO_LEVEL, x)
#define DEBUG(x...)   init_klog_write(KLOG_DEBUG_LEVEL, x)
#define VERBOSE(x...) init_klog_write(KLOG_DEBUG_LEVEL, x)
 

呼叫NOTICE函式，也就調到了函式init_klog_wirte傳入的引數為NOTICE log level，如果呼叫別的函式就傳入對應的log level。還有傳入需要列印的資訊。

先看一下各個log level的值，程式碼定義位置system/core//include/cutils/klog.h

#define KLOG_ERROR_LEVEL   3
#define KLOG_WARNING_LEVEL 4
#define KLOG_NOTICE_LEVEL  5
#define KLOG_INFO_LEVEL    6
#define KLOG_DEBUG_LEVEL   7

繼續分析程式碼system/core/init/log.cpp

void init_klog_write(int level, const char* fmt, ...) {
    va_list ap;
    va_start(ap, fmt);
    init_klog_vwrite(level, fmt, ap);        //函式呼叫
    va_end(ap);
}

static void init_klog_vwrite(int level, const char* fmt, va_list ap) {
    static const char* tag = basename(getprogname());

    if (level > klog_get_level()) return;      //之前設定的level為NOTICE 5，現在level也為5相等為false，INFO level為6所以return

    // The kernel's printk buffer is only 1024 bytes.
    // TODO: should we automatically break up long lines into multiple lines?
    // Or we could log but with something like "..." at the end?
    char buf[1024];             //kernel 的printk buffer只有1024個位元組， 將長的單行log，變為多行，或者直接省略掉
    size_t prefix_size = snprintf(buf, sizeof(buf), "<%d>%s: ", level, tag);
    size_t msg_size = vsnprintf(buf + prefix_size, sizeof(buf) - prefix_size, fmt, ap);
    if (msg_size >= sizeof(buf) - prefix_size) {
        msg_size = snprintf(buf + prefix_size, sizeof(buf) - prefix_size,
                            "(%zu-byte message too long for printk)\n", msg_size);
    }

    iovec iov[1];
    iov[0].iov_base = buf;
    iov[0].iov_len = prefix_size + msg_size;

    klog_writev(level, iov, 1);       //傳送整理好的資訊
}

system/core/libcutils/klog.c

void klog_writev(int level, const struct iovec* iov, int iov_count) {
    if (level > klog_level) return;           //由於level與klog_level都為5,所以繼續執行
    if (klog_fd < 0) klog_init();               //前面已經初始化過klog_fd大於等於0
    if (klog_fd < 0) return;                     
    TEMP_FAILURE_RETRY(writev(klog_fd, iov, iov_count));   
}

//system/core/include/log/uio.h
extern int  readv( int  fd, struct iovec*  vecs, int  count );   //定義readv函式
extern int  writev( int  fd, const struct iovec*  vecs, int  count );  /定義writev函式

//system/core/liblog/uio.c
#include <log/uio.h>
LIBLOG_ABI_PUBLIC int writev(int fd, const struct iovec *vecs, int count)
{
    int   total = 0;

    for ( ; count > 0; count--, vecs++ ) {
        const char*  buf = vecs->iov_base;
        int          len = vecs->iov_len;

        while (len > 0) {
            int  ret = write( fd, buf, len ); //呼叫linux的write函式，fd為/dev/kmsg的檔案描述符，所以將log寫入到kmsg中即kernel log中。
            if (ret < 0) {
                if (total == 0)
                    total = -1;
                goto Exit;
            }
            if (ret == 0)
                goto Exit;

            total += ret;
            buf   += ret;
            len   -= ret;
        }
    }
Exit:
    return total;
}

    之前做專案時遇到一個問題，在開機過程中kernel 與 init程序中的log都輸在kernel log中，而啟動zygote之後log是輸出在android中的，這樣就發生了init程序到framework這段時間無法精確計算，對分析開機流程總耗時帶來不小的困擾。所以我們就仿照klog自己定義TAG來輸出資訊，將android 中的log輸出到kernel中，這樣同一行log即在kernel log中有也在android log中有就可以精確計算時間了。

首先在system/core/include/cutils/klog.h中定義log level

	#define KLOG_PERFORMANCE_LEVEL 0              //根據之前分析，將level設定小一點，至少要小於5
	#define KLOG_BOOTINFO(tag,x...) klog_write(KLOG_PERFORMANCE_LEVEL, "<0>" tag ": " x)    //定義函式關係

定義完之後就可以在framework中使用了，

例如init程序啟動完zygote服務，會進入/frameowrk/base/cmds/app_process/app_main.cpp我們可以在這裡使用

#include <cutils/klog.h>              //先include對應的標頭檔案
#define BOOTINFO(x...) KLOG_BOOTINFO("bootinfo", x)       //定義對應的函式關係

 BOOTINFO("Entered app_main.cpp main() \n");    //就可以通過BOOTINFO函式將log輸出到kernel log中

不過將編譯好的檔案替換到手機中仍然無法輸出對應log資訊，經過分析發現是有與selinux許可權，輸出log存在selinux安全問題。

為了除錯我們本地只好將selinux關閉了，程式碼還是在init .cpp 中我們之前將init程序時有過提到。

static void selinux_initialize(bool in_kernel_domain) {
    Timer t;

    //..............
    if (in_kernel_domain) {
       //.........

        bool kernel_enforcing = (security_getenforce() == 1);
        bool is_enforcing = selinux_is_enforcing();
        if (kernel_enforcing != is_enforcing) {
            if (security_setenforce(is_enforcing)) {     //可以直接將is_enforcing改為false，就將selinux關閉了
                ERROR("security_setenforce(%s) failed: %s\n",
                      is_enforcing ? "true" : "false", strerror(errno));
                security_failure();
            }
        }

        //.............
    } else {
        selinux_init_all_handles();
    }
}