大家在平日的android开发中,可能每个人负责的模块不一样,所以接触到的代码别人有些也不熟悉,但是有一个模块肯定对于几乎所有人都是知道的,工作中肯定也是都会接触到了,那就是日志模块,也叫log。虽然log对具体的每个功能没有直接的影响,但是却对开发来说至关重要,我们开发出的程序不可能没有问题,一旦有问题,尤其是一些疑难杂症,如果不通过log来分析的话,那要解决问题无疑是非常困难的,所以每个人可以是开发不同模块的,但是对于log不可能不知道,所以今天就来分析下android的日志模块,从最上层到底层,整个流程走一遍,让我们可以知道日志的完整工作流程,其实如果把日志看出是一个应用的话,通过分析log模块,也可以是一个了解android系统整体运行架构的例子,好了,话不多说,走起。
开始我们就从平时我们最常用的输出log代码作为起点:
```java
import android.util.Log
Log.v("isTag","isMsg");
```
我们代码中用了一个最常用的log输出语句,它的优先级是v,标签是isTag,日志内容是isMsg。 这个是最基本都语句,不多说了,我们可以看到这个方法在android.util.Log包下的Log类中,我们跟进去看一下:
```java
// android.util.Log
// 日志类型
public static final int LOG_ID_MAIN = 0;
public static final int LOG_ID_RADIO = 1;
public static final int LOG_ID_EVENTS = 2;
public static final int LOG_ID_SYSTEM = 3;
// 优先级
public static final int VERBOSE = 2;
public static final int DEBUG = 3;
public static final int INFO = 4;
public static final int WARN = 5;
public static final int ERROR = 6;
public static final int ASSERT = 7;
@UnsupportedAppUsage
public static native int println_native(int bufID, int priority, String tag, String msg);
public static int v(@Nullable String tag, @NonNull String msg) {
return println_native(LOG_ID_MAIN, VERBOSE, tag, msg);
}
```
我把相关的代码贴了出来,可以看到通过调用Log.v函数我们调用了Log类中的v方法,他的两个参数就是上层传过来的,最终他调用了jni的方法println_native,这个jni方法我们下面马上来看,这里先说下这个jni前面2个参数,第二个参数VERBOSE这个很好理解,这个是指定了log的优先级,我们既然调用的是v方法,自然他的优先级是VERBOSE,可以看到上面的定义,优先级是从2到7的六个等级(为什么没有1?这个暂时我有不知道,不影响源码的阅读,先过)。
然后第一个参数LOG_ID_MAIN,这个表示是这个日志的类型,我们可以看到在最上面一共有0到4五种类型的日志设备,大多数情况上层开发main这种日志类型比较多,其他还有系统的system,一些无线设备有关的radio,系统设备行为相关的event。每种类型的日志都会作为一种独立的设备来看待,所以他们输出日志的地方都是独立的。在linux内核层,每一种设备都被作为一个文件来看待,所以这里几种设备对linux系统来说就是几个文件,操作之间就和一般文件一样打开就可以,用完了再关闭。这里到后面分析到底层的时候可以在看下,这里简单说就是通过指定日志设备类型,优先级,标签以及日志内容来开始输出日志了。
下面我们接着看前面说到的jni方法:
```c++
// 文件路径 framework/base/core/jni/android_util_Log.cpp
static jint android_util_Log_println_native(JNIEnv* env, jobject clazz,
jint bufID, jint priority, jstring tagObj, jstring msgObj)
{
const char* tag = NULL;
const char* msg = NULL;
if (msgObj == NULL) { // 内容是空,抛异常
jniThrowNullPointerException(env, "println needs a message");
return -1;
}
if (bufID < 0 || bufID >= LOG_ID_MAX) { // 设备号不对,抛异常
jniThrowNullPointerException(env, "bad bufID");
return -1;
}
if (tagObj != NULL) // 如果tag非空,获取tag字符串
tag = env->GetStringUTFChars(tagObj, NULL);
msg = env->GetStringUTFChars(msgObj, NULL); // 获取内容字符串
int res = __android_log_buf_write(bufID, (android_LogPriority)priority, tag, msg); // 写入指定类型日志
if (tag != NULL)
env->ReleaseStringUTFChars(tagObj, tag);
env->ReleaseStringUTFChars(msgObj, msg);
return res;
}
```
这个方法可以看到前面部分主要就是对上面传过来的参数做一些校验,比如是否为空,是否在有效区间范围内等等,最终继续会调用__android_log_buf_write这个方法写入指定日志类型,把参数继续往后面传。这个方法见下面:
```c++
// 文件路径 system/logging/liblog/logger_write.c
// __android_log_assert,__android_log_vprint,__android_log_print都会通过这个方法来写入日志,bufID参数是日志设备类型
LIBLOG_ABI_PUBLIC int __android_log_buf_write(int bufID, int prio,
const char *tag, const char *msg)
{
struct iovec vec[3];
char tmp_tag[32]; // 临时变量,如果设备类型被修改的话,用来修改标签的值
if (!tag) // 如果没有标签
tag = ""; // tag就赋值为""
/* XXX: This needs to go! */ // 下面这些语句的意思是tag以这些字母开头的话日志设备类型会被赋值为LOG_ID_RADIO
if ((bufID != LOG_ID_RADIO) &&
(!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"))) {
bufID = LOG_ID_RADIO;
snprintf(tmp_tag, sizeof(tmp_tag), "use-Rlog/RLOG-%s", tag); // 修改tag的值
tag = tmp_tag; // 重新给tag赋值
}
#if __BIONIC__
if (prio == ANDROID_LOG_FATAL) {
android_set_abort_message(msg);
}
#endif
vec[0].iov_base = (unsigned char *)&prio; // 写入优先级
vec[0].iov_len = 1; // 优先级大小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(bufID, vec, 3); // 继续调用其他函数
}
struct iovec {
void * iov_base;
size_t iov_len;
};
```
这个方法在已经不算是framework层了,从他所在的路径system/logging/liblog,可以看出他是一个运行时库,是作为用户态和内核态的桥梁。
这个方法会通过对tag做一些判断,以这些开头的会认为是radio类型的日志,所以会重新设置设备类。这里用到了一个结构体iovec,这个结构体也很简单,就2个字段,一个存储数据的地址,另一个保存数据的长度。这里的结构体数组有3个元素,分别保存日志的优先级,标签和内容,然后通过write_to_log函数继续往下走。
```c
static int (*write_to_log)(log_id_t, struct iovec *vec, size_t nr) = __write_to_log_init;
static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1 }; // 文件描述符数组
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_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;
if (log_fds[LOG_ID_MAIN] < 0 || log_fds[LOG_ID_RADIO] < 0 ||
log_fds[LOG_ID_EVENTS] < 0) { // 如果打开几个设备文件失败重置以下一些变量
log_close(log_fds[LOG_ID_MAIN]);
log_close(log_fds[LOG_ID_RADIO]);
log_close(log_fds[LOG_ID_EVENTS]);
log_fds[LOG_ID_MAIN] = -1;
log_fds[LOG_ID_RADIO] = -1;
log_fds[LOG_ID_EVENTS] = -1;
write_to_log = __write_to_log_null;
}
if (log_fds[LOG_ID_SYSTEM] < 0) { // 如果LOG_ID_SYSTEM打开失败,把LOG_ID_SYSTEM重定向到LOG_ID_MAIN,即把system的日志写入到main中
log_fds[LOG_ID_SYSTEM] = log_fds[LOG_ID_MAIN];
}
}
#ifdef HAVE_PTHREADS
pthread_mutex_unlock(&log_init_lock);
#endif
return write_to_log(log_id, vec, nr); // 此时初始化正常情况下,write_to_log已经指向了__write_to_log_kernel
}
```
可以看到write_to_log方法是指向另一个方法__write_to_log_init的,所以我们继续要看__write_to_log_init方法。
方法开始判断如果定义了HAVE_PTHREADS宏,需要上锁,这里为了防止线程竞争导致问题。由于write_to_log最开始是指向这个方法自己的,所以说如果是第一次运行到这里需要做初始化,这里分别打开了四个文件,如下:
```c++
static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1 };
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);
```
首先说下log_fds,这个是一个整型数组,他保存了所有日志设备的文件描述符。这里简单介绍下文件描述符的概念,在linux中所有都是文件,在一个进程中如果要使用一个设备,不管是真设备还是一个虚拟设备,比如我们这里日志就可以被看做一个虚拟的设备,都需要先打开他们。打开他们这个怎么理解呢?简单说就是获取这个设备的信息,一个设备或者一个文件一旦需要被使用,肯定需要在内存中开辟一块空间,然后系统在这块空间上做读写操作,如果有了写操作还需要回写给外设等等一系列操作。这块在内存中开辟的空间就是属于这个设备的,在linux中会用inode这个数据结构来保存每一个设备(当然不止设备,所有文件都会用inode来表示,文件,目录,设备等等),所以只要拿到了inode就知道了他对应的对象的所有信息,由于每种设备都有一个唯一的编号,如果有多个相同设备的话,他们的子编号都是不同的,这些信息都会在inode里面获取。
在linux的设计中,会有一片内存区域专门用作inode节点的位图,另外有一片区域专门保存inode具体的对象,这两者是对应起来的,通过位图中置1的下标就可以找到具体保存的对象数据,然后从对象中就可以获取具体的信息了。所以这里打开一个日志设备就是返回的就是inode位图的下标,只要有了这个下标就可以找到这个日志设备的inode的对象,对象中会有需要读写的具体地址,从而我们就可以进行读写操作了。
说了这么多,反正就是需要把具体的日志设备对应的inode位图小标拿到手,然后保存起来就可以了,这样以后就可以直接用了。获取文件描述符后,会把write_to_log指向__write_to_log_kernel这个方法。然后会经过一些判断是否拿到的数据正常,如果不正常会把write_to_log指向一个返回-1的方法__write_to_log_null。最后会重新执行这个方法自己,因为如果不正常的话会返回-1,正常的话由于现在这个方法已经指向__write_to_log_kernel了,所以会去执行__write_to_log_kernel这个方法。下面就看下这个方法:
```c
#define log_writev(filedes, vector, count) writev(filedes, vector, count)
static int __write_to_log_kernel(log_id_t log_id, struct iovec *vec, size_t nr) // 最终调用writev,写入日志
{
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_id这个参数是日志设备号,如果在设备号正常返回内,会把前面初始化时候保存的文件描述符取出来,最后调用log_writev方法去写日志。log_writev是一个宏定义具体的方法是writev。
```c
int writev( int fd, const struct iovec* vecs, int count )
{
int total = 0;
for ( ; count > 0; count--, vecs++ ) { // 遍历iovec
const char* buf = (const char*)vecs->iov_base; // 取出数据地址
int len = (int)vecs->iov_len; // 取出数据长度
while (len > 0) {
int ret = write( fd, buf, len ); // 把buf开始的len个字节写入文件描述符fd的设备中
if (ret < 0) { // 小于0,报错
if (total == 0)
total = -1;
goto Exit;
}
if (ret == 0) // 等于0表示没有写入,报错
goto Exit;
total += ret;
buf += ret;
len -= ret;
}
}
Exit:
return total;
}
```
这个方法也很好理解,目前我们所需要的数据都保存在iovec中,我们就遍历他,然后写入日志设备中。
```c
ssize_t write(int fd, const void* buf, size_t count)
{
CALLTRACEV("%s\n", __FUNCTION__);
FakeDev* dev = wsFakeDevFromFd(fd); // 取出设备
if (dev != NULL) {
return dev->write(dev, fd, buf, count); // 调用设备的写方法
} else {
CALLTRACE("write(%d, %p, %u)\n", fd, buf, count);
return _ws_write(fd, buf, count);
}
}
```
这里可以看到最终通过文件描述符取出设备后,把数据写入了设备中,这里方法会进入内核态去写,写完后会返回写入的字节数,这样整个写入日志的过程就完成了,进入内核的写过程,我们第二篇文章再说,起码目前在用户态从app调用Log函数,然后经过jni再到运行时库,最后陷入内核来执行写操作,其实是非常典型的一个从上层到底层的运行过程,好了,今天就到这里了,我们下篇文章再见。
Android日志模块解析一