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

https://www.jianshu.com/p/0e4cd3867a8e

一、总体介绍

  安卓日志系统是开发者比较熟悉的模块,每个开发者在开发中都会是用到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日志系统框图

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

应用层接口:

  在应用层,安卓系统封装了日志系统的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程序中打印日志。

native api

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

核心logd

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

  logd 对外维护了3个socket api:

dev/socket/logd    传输控制指令

dev/socket/logw    写日志

dev/socket/logr    读日志

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 发送消息的流程,

  详细过程如下:

客户端进程通过SDK 中提供的接口写入日志;

Log.d(TAG,“Message body”);

java代码通过JNI 调用liblog;

android_util_Log_println_native

liblog封装了logd访问的socket接口;liblog通过socket通信,完成客户端日志写入logd;

__android_log_buf_writewrite_to_log__write_to_log_init__write_to_log_daemonwrite_transport_for_each logdWrite.writelogdWrite

logd中维护main / system / crash 等各个log buffer,各个模块的日志缓存在此buffer中。

LogListener::onDataAvailableLogBuffer::log=>stats.add(elem);maybePrune(elem->getLogId());

三、读日志流程分析

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

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

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

process_read_log_step2.png

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

四、日志系统的核心 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.rc 中定义了logd 为一个native service,在启动服务时,会建立三个socket为后面通信进行准备。

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

下图就是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,导致应用或者整机卡顿,产生性能问题。

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

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,542评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,596评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 158,021评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,682评论 1 284
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,792评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,985评论 1 291
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,107评论 3 410
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,845评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,299评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,612评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,747评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,441评论 4 333
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,072评论 3 317
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,828评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,069评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,545评论 2 362
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,658评论 2 350

推荐阅读更多精彩内容