深入理解安卓日志系统(logcat / liblog / logd)

5,849 阅读7分钟

一、总体介绍

  安卓日志系统是开发者比较熟悉的模块,每个开发者在开发中都会是用到Log.d 等接口打印日志,通过logcat 查看打印的日志定位问题。本文通过深入分析日志系统相关模块和源码,使得开发者更深入的了解打印日志和存储日志相关技术原理,从而更高效的利用日志系统。

  本文会介绍用户空间的Android日志系统,不包含linux kernel 日志;也不包含crash / ANR / tombstone / kernel panic等异常日志的收集流程。

  本文基于Android 9.0 系统源码。其中liblog,logd 在安卓10,安卓11版本上差别不大。 虽然logcat 在Android 10 上用C++ 进行了重构,但是其基本业务逻辑的接口都没有变化。需要注意的是,本文没有强调具体的代码逻辑,而是从设计角度出发分析,重在理清模块之前的接口和对应模块的基本功能。

1.1 系统框架

Android日志系统框图

  安卓日志系统从上到下如上图所示:

  1. 应用层接口:

  在应用层,安卓系统封装了日志系统的Java接口,Log.java, Rlog.java, Slog.java EventLog.java。应用开发者比较熟悉Log.java,系统开发者对 Rlog,Slog,EventLog, 接口会比较熟悉。这几个接口作用类似,都是写入日志,差别是写入logd的日志节点不同。

  Java 接口封装在android.jar 中,作为SDK提供给开发者使用,在运行时通过libandroid_runtime.so 中的JNI 接口调用系统native api。

  对于C/C++ 的开发者,可以直接使用 log.h 中提供的ALOGD 等系列API 在native程序中打印日志。

  1. native api

  日志系统的核心服务的logd,一个native守护进程。为了访问logd提供的api,安卓系统封装了一层liblog,便于应用层方便访问logd 的socket api

  1. 核心logd

  logd是日志系统的核心,开机时由init进程启动,在系统后台持续运行。logd维护了一个RAM buffer, 作为日志的缓存。各个进程的日志都会写入这个RAM buffer。如果日志写入过多,会删除最老的日志,删除算法类似于ring buffer的逻辑。

  logd 对外维护了3个socket api:

  • dev/socket/logd    传输控制指令

  • dev/socket/logw    写日志

  • dev/socket/logr     读日志

  1. native bin

  在native 层,安卓提供了一个/system/bin/logcat native 命令行程序,作为一个统一的客户端通信进程。开发者通过 adb logcat 相关指令可以读日志或者给logd发送指令。

1.2 系统设计

从设计上看,日志系统模块是一个典型的生产者-消费者模式的系统:

  • 各个客户端进程是日志生产者;

  • logcat 是日志的消费者,可包含多个消费者进程;

  • 消息队列是ring buffer,超过门限进行日志裁减。

模块需要提供的功能约束:

  • 跨进程访问:多个进程可以并发读写;

  • 提供各个模块方便读写日志的接口;

  • 日志buffer 可以分类存储;

  • 与Kernel解耦设计,等等

  在Android 5.0 之前,logd进程并不存在,日志是保留在/dev/log/main, /dev/log/system, /dev/log/radio,/dev/log/event 等各个节点的。但是这样要求每次安卓大版本升级,linux kernel 需要升级对应的日志驱动。因此,后续Google 重构了日志系统,新建logd进程,在客户端保留日志。

二、写日志流程分析

process_wirte_log_new.png

  写入日志的流程实际上是客户端通过 dev/socket/logdw 发送消息的流程,

  详细过程如下:

  1. 客户端进程通过SDK 中提供的接口写入日志;
Log.d(TAG, “Message body”);
  1. java代码通过JNI 调用liblog;
  android_util_Log_println_native
  1. liblog封装了logd访问的socket接口;liblog通过socket通信,完成客户端日志写入logd;
  __android_log_buf_write
write_to_log
__write_to_log_init
__write_to_log_daemon
write_transport_for_each
 logdWrite.write
logdWrite
  1. logd中维护main / system / crash 等各个log buffer,各个模块的日志缓存在此buffer中。
LogListener::onDataAvailable
LogBuffer::log
=>     stats.add(elem);
         maybePrune(elem->getLogId());

三、读日志流程分析

process_read_log_step1.png   同样,读取日志的流程实际上是客户端通过 dev/socket/logdr 读取消息的流程,详细过程可以参考上面的图片,这里不再赘述。

  和写日志不同,日志在logd中存储是有特定格式的,logcat需要把日志格式解析为命令行中可以看到的字符串。因此有processBuffer 的过程。

  如果logcat把文件要打印到日志文件中,如果超过了文件大小,logcat需要调用rotateLogs方法建立新的文件。

process_read_log_step2.png

  在Android 9.0 中,一个日志条目在logd中是按照如下结构定义存储的。

log_item.png

四、日志系统的核心 logd

4.1 logd 进程框架

logd_structure.png

  logd 是日志系统的核心进程,由init启动,是一个deamon 进程常驻后台;

  进程的主要作用是维护各个日志节点buffer队列,提供socket接口进行读、写、控制功能。

  如上图所示:logd进程启动后,分别启动了LogReader, LogListener,CommandListener 三个线程,处理来自三个socket的消息。在收到消息后,会通过LogBuffer类保存日志到对应的RAM buffer中。

  LogAudit 是接收Kernel selinux 相关事件的模块,可以在用户空间打印selinux的相关日志信息。

  LogKlog 是接收kernel 日志的模块,通过设置property,可以通过logcat命令读取kernel 日志。

  LogStatistics 是日志统计模块,默认开启统计数据较少,仅能以pid/uid 纬度统计打印日志的数量。如果设置了logd.statistic = true。会打印更多纬度的统计信息,包括哪些pid/uid/tid/TAG日志量比较大,对于裁减日志有很大帮助。

4.2 logd 启动流程

logd_init_rc.png

  在logd.rc 中定义了logd 为一个native service,在启动服务时,会建立三个socket为后面通信进行准备。

  这里有一个细节:lodw 之所以定义为 dgram 类型的socket,可以理解为UDP 类型的socket,主要是考虑到性能问题:各个进程在写日志的时候,write 方法写入到socket的buffer中即可返回,不会block 业务逻辑太长时间。如果是TCP 类型的socket,客户端需要等到TCP收到ACK 响应才能返回,打印日志存在多余的性能消耗。

  下图就是logd 启动的流程:

logd初始化

五、日志统计功能分析

  如果日志太多怎么办,怎么找出是哪个进程打印了过多的日志?

  logcat 本身提供了一个 -S 参数,可以对日志进行统计。

  在设置 logd.statistics = true 的配置项后,可以打印出更多日志统计信息,包括pid/uid/tid/TAG 等统计维度的信息。

  adb shel logcat -S 命令执行过程如下图所示,核心是-S 参数设置了printStatistics 标志位为 true,logcat 通过 /dev/socket/logd 向logd发送请求,打印LogStatistics模块存储的统计信息。

日志统计

六、总结

  洋洋洒洒一大篇文字,实际上想说明一个问题,打印日志实际上有很多资源消耗的,包括:

1 跨进程通信的消耗:日志信息通过socket 发送到 logd;

2 内存消耗:logd中要维护对应的buffer。RAM 资源的消耗;

3 CPU 资源的消耗:logd中ring buffer会经常进行pruneLogs 操作,删减日志,耗费CPU资源。

4 IO消耗:在某些产品上,log会在后台进程/线程中写入文件,这些更会大量消耗IO,导致应用或者整机卡顿,产生性能问题。

  因此,阅读过本文的开发者,希望在每次打日志时也能深思熟虑,更有效地,更矜持地打印日志。