安卓binder驱动内核日志调试打印开放及原理（第一节）

原创 2025-03-04 16:21:51 1.2k 阅读 AI写同款

收录于

binder

千里马学框架

码龄6年墨衍会员 · AI 创作全网分发

1万+粉丝650篇原创

关注

Android应用启动性能优化：Binder通信机制源码深度解析进程间通信（IPC）是操作系统实现多进程协作的核心机制，它允许不同进程安全高效地交换数据和指令。在Android系统中，Binder作为其特有的IPC机制，通过一次拷贝、内存映射等设计，在性能与安全性之间取得了平衡，成为系统服务与应用进程间通信的基石。从技术价值看，Binder不仅保障了系统架构的清晰分层与安全隔离，更是应用启动流畅性、系统响应速度的关键支撑。在应用启动这一典型场景中，从Launcher点击图标到Activity界面显示，AMS、Zygote、应用进程三者间数十次的Binder调用构成了启动阅读详情

AI摘要

在系统开发中，binder通讯内核日志正常不打印，开放会影响系统性能。本文介绍开放binder调试日志的方法，通过控制debug_mask值来实现，还说明了debug_mask的位置及写入值的计算方式，如多个枚举值做或运算，此外还提及binder_alloc相关日志写入方式。

背景：

经常有学员朋友在做系统开发时候，有时候遇到binder相关的一些问题，这个时候可能就需要比较多的binder相关日志，但是正常情况下这些binder通讯的的内核日志都是没有的打印的，因为经常binder通讯太过于频繁，如果正常版本都开放出来这些binder调试日志，那样会让系统卡顿，影响性能。
但是在分析binder驱动源码时候又可以看到类似如下日志：
在这里插入图片描述那么到底该怎么让这些日志可以打印出来呢？下面给大家介绍一下相关的打开日志的命令。
这里binder内核日志相关准备分为两节给大家分享：
第一节：主要介绍相关实战命令的使用让大家学会用命令去开放日志
第二节：主要介绍binder调试日志相关的源码分析和控制原理

实战调试命令：

通过控制debug_mask值来控制相关的binder调试日志的打开，那么debug_mask值的依据是什么呢？那就是来源下面这个枚举：
kernel-aosp14/common/drivers/android/binder.c

enum {
	BINDER_DEBUG_USER_ERROR             = 1U << 0, // 1
	BINDER_DEBUG_FAILED_TRANSACTION     = 1U << 1, // 2
	BINDER_DEBUG_DEAD_TRANSACTION       = 1U << 2, // 4
	BINDER_DEBUG_OPEN_CLOSE             = 1U << 3, // 8
	BINDER_DEBUG_DEAD_BINDER            = 1U << 4, // 16
	BINDER_DEBUG_DEATH_NOTIFICATION     = 1U << 5, // 32
	BINDER_DEBUG_READ_WRITE             = 1U << 6, // 64
	BINDER_DEBUG_USER_REFS              = 1U << 7, // 128
	BINDER_DEBUG_THREADS                = 1U << 8, // 216
	BINDER_DEBUG_TRANSACTION            = 1U << 9, // 512
	BINDER_DEBUG_TRANSACTION_COMPLETE   = 1U << 10,// 1024
	BINDER_DEBUG_FREE_BUFFER            = 1U << 11,// 2048
	BINDER_DEBUG_INTERNAL_REFS          = 1U << 12,// 4096
	BINDER_DEBUG_PRIORITY_CAP           = 1U << 13,// 8192
	BINDER_DEBUG_SPINLOCKS              = 1U << 14,// 16384
};

比如上面背景中我们看到有binder_debug打印，它带的参数是BINDER_DEBUG_OPEN_CLOSE
在这里插入图片描述
那么从枚举得出BINDER_DEBUG_OPEN_CLOSE = 1U << 3, // 8
所以只需要对debug_mask写入 8既可以实现让binder的中所有BINDER_DEBUG_OPEN_CLOSE相关binder_debug打印出来。

那么这个debug_mask在哪里呢？这里先直接告诉大家，是在如下目录：

NX563J:/sys/module/binder/parameters # ls
debug_mask  devices  stop_on_user_error

简单说就是在/sys/module/binder/parameters/debug_mask,这里的debug_mask文件就是要写入的文件
比如写入上面的值BINDER_DEBUG_OPEN_CLOSE为8 （注意一般需要debug机器）

NX563J:/ # echo 8 >  /sys/module/binder/parameters/debug_mask

然后这个时候抓取日志看看是否有显示binder的open相关日志：

130|NX563J:/ # logcat -b all -c;logcat -b kernel | grep binder                                                                                                                                                    




03-04 00:33:46.170     0     0 I binder  : 30418 close vm area da398000-da496000 (1016 K) vma 10220051 pagep 60000000000f53
03-04 00:33:46.172     0     0 I binder  : binder_flush: 30418 woke 0 threads
03-04 00:33:46.172     0     0 I binder  : binder_deferred_release: 30418 threads 5, nodes 2 (ref 3), refs 8, active transactions 0
03-04 00:33:46.187     0     0 I binder  : 30385 close vm area 75d915f000-75d925d000 (1016 K) vma 10220051 pagep 60000000000f53
03-04 00:33:46.187     0     0 I binder  : 30385 close vm area 765da4f000-765db4d000 (1016 K) vma 10220051 pagep 60000000000f53
03-04 00:33:46.187     0     0 I binder  : binder_flush: 30385 woke 0 threads
03-04 00:33:46.187     0     0 I binder  : binder_flush: 30385 woke 0 threads
03-04 00:33:46.188     0     0 I binder  : binder_deferred_release: 30385 threads 1, nodes 0 (ref 0), refs 3, active transactions 0
03-04 00:33:46.195     0     0 I binder  : binder_deferred_release: 30385 threads 11, nodes 50 (ref 51), refs 53, active transactions 0
03-04 00:33:47.224     0     0 I binder  : binder_open: 30512:30512
03-04 00:33:47.224     0     0 I binder  : 30512:30512 ioctl 40046210 7fd05b5cc0 returned -22
03-04 00:33:47.224     0     0 I binder  : binder_mmap: 30512 765db5c000-765dc5a000 (1016 K) vma 200071 pagep 60000000000f53
03-04 00:33:47.499     0     0 I binder  : binder_open: 30512:30536
03-04 00:33:47.499     0     0 I binder  : 30512:30536 ioctl 40046210 765d23af04 returned -22
03-04 00:33:47.499     0     0 I binder  : binder_mmap: 30512 75f1646000-75f1744000 (1016 K) vma 200071 pagep 60000000000f53
03-04 00:33:53.466     0     0 I binder  : binder_open: 30556:30556
03-04 00:33:53.466     0     0 I binder  : 30556:30556 ioctl 40046210 7fd05b5cc0 returned -22
03-04 00:33:53.466     0     0 I binder  : binder_mmap: 30556 765db56000-765dc54000 (1016 K) vma 200071 pagep 60000000000f53
03-04 00:33:53.619     0     0 I binder  : binder_open: 30556:30579
03-04 00:33:53.619     0     0 I binder  : 30556:30579 ioctl 40046210 765d23af04 returned -22
03-04 00:33:53.619     0     0 I binder  : binder_mmap: 30556 765cfa9000-765d0a7000 (1016 K) vma 200071 pagep 60000000000f53

明显可以看到open，closer日志

如果想要多个开放多个枚举，那么只需要做或运算，然后最后结果写入 debug_mask既可以
比如开放如下几个枚举：

BINDER_DEBUG_USER_ERROR             = 1U << 0, // 1
BINDER_DEBUG_FAILED_TRANSACTION     = 1U << 1, // 2
BINDER_DEBUG_DEAD_TRANSACTION       = 1U << 2, // 4
BINDER_DEBUG_OPEN_CLOSE             = 1U << 3, // 8

那么最后写入的值就是8 + 4+ 2+ 1 = 15

NX563J:/ # echo 15 >  /sys/module/binder/parameters/debug_mask

和binder相关的/sys/module/还有一个binder_alloc,它主要是binder 申请相关的日志，这里枚举有差异

kernel-aosp14/common/drivers/android/binder_alloc.c

enum {
	BINDER_DEBUG_USER_ERROR             = 1U << 0, // 1
	BINDER_DEBUG_OPEN_CLOSE             = 1U << 1, // 2
	BINDER_DEBUG_BUFFER_ALLOC           = 1U << 2, // 4
	BINDER_DEBUG_BUFFER_ALLOC_ASYNC     = 1U << 3, // 8
};

这里写入值方式和binder下面节点一样

NX563J:/ # echo 7 >  /sys/module/binder_alloc/parameters/debug_mask

写完后可以看到日志有大量的alloc相关打印：

03-04 00:42:12.716     0     0 I binder_alloc: 15501: binder_alloc_buf size 128 got buffer 0000000000000000 size 1040384
03-04 00:42:12.716     0     0 I binder_alloc: 15501: allocate pages 0000000000000000-0000000000000000
03-04 00:42:12.716     0     0 I binder_alloc: 15501: add free buffer, size 1040256, at 0000000000000000
03-04 00:42:12.716     0     0 I binder_alloc: 15501: binder_alloc_buf size 128 got 0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15501: binder_free_buf 0000000000000000 size 128 buffer_size 128
03-04 00:42:12.717     0     0 I binder_alloc: 15501: free pages 0000000000000000-0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15501: merge free, buffer 0000000000000000 do not share page with 0000000000000000 or 0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15501: free pages 0000000000000000-0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15501: add free buffer, size 1040384, at 0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15733: binder_alloc_buf size 9648 got buffer 0000000000000000 size 1040384
03-04 00:42:12.717     0     0 I binder_alloc: 15733: allocate pages 0000000000000000-0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15733: add free buffer, size 1030736, at 0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15733: binder_alloc_buf size 9648 got 0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15733: binder_free_buf 0000000000000000 size 9648 buffer_size 9648
03-04 00:42:12.717     0     0 I binder_alloc: 15733: free pages 0000000000000000-0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15733: merge free, buffer 0000000000000000 do not share page with 0000000000000000 or 0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15733: free pages 0000000000000000-0000000000000000
03-04 00:42:12.717     0     0 I binder_alloc: 15733: add free buffer, size 1040384, at 0000000000000000
03-04 00:42:12.963     0     0 I binder_alloc: 15501: binder_alloc_buf size 304 got buffer 0000000000000000 size 304
03-04 00:42:12.963     0     0 I binder_alloc: 15501: allocate pages 0000000000000000-0000000000000000
03-04 00:42:12.963     0     0 I binder_alloc: 15501: binder_alloc_buf size 304 got 0000000000000000
03-04 00:42:12.963     0     0 I binder_alloc: 1114: binder_free_buf 0000000000000000 size 48 buffer_size 48
03-04 00:42:12.963     0     0 I binder_alloc: 1114: free pages 0000000000000000-0000000000000000
03-04 00:42:12.963     0     0 I binder_alloc: 1114: merge free, buffer 0000000000000000 do not share page with 0000000000000000 or 0000000000000000
03-04 00:42:12.963     0     0 I binder_alloc: 1114: free pages 0000000000000000-0000000000000000
03-04 00:42:12.963     0     0 I binder_alloc: 1114: add free buffer, size 1040384, at 0000000000000000
03-04 00:42:12.964     0     0 I binder_alloc: 15501: binder_free_buf 0000000000000000 size 304 buffer_size 304
03-04 00:42:12.964     0     0 I binder_alloc: 15501: free pages 0000000000000000-0000000000000000
03-04 00:42:12.964     0     0 I binder_alloc: 15501: add free buffer, size 304, at 0000000000000000
03-04 00:42:12.964     0     0 I binder_alloc: 1114: binder_alloc_buf size 48 got buffer 0000000000000000 size 1040384
03-04 00:42:12.964     0     0 I binder_alloc: 1114: allocate pages 0000000000000000-0000000000000000
03-04 00:42:12.964     0     0 I binder_alloc: 1114: add free buffer, size 1040336, at 0000000000000000
03-04 00:42:12.964     0     0 I binder_alloc: 1114: binder_alloc_buf size 48 got 0000000000000000