背景:
经常有学员朋友在做系统开发时候,有时候遇到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, // 1BINDER_DEBUG_FAILED_TRANSACTION = 1U << 1, // 2BINDER_DEBUG_DEAD_TRANSACTION = 1U << 2, // 4BINDER_DEBUG_OPEN_CLOSE = 1U << 3, // 8BINDER_DEBUG_DEAD_BINDER = 1U << 4, // 16BINDER_DEBUG_DEATH_NOTIFICATION = 1U << 5, // 32BINDER_DEBUG_READ_WRITE = 1U << 6, // 64BINDER_DEBUG_USER_REFS = 1U << 7, // 128BINDER_DEBUG_THREADS = 1U << 8, // 216BINDER_DEBUG_TRANSACTION = 1U << 9, // 512BINDER_DEBUG_TRANSACTION_COMPLETE = 1U << 10,// 1024BINDER_DEBUG_FREE_BUFFER = 1U << 11,// 2048BINDER_DEBUG_INTERNAL_REFS = 1U << 12,// 4096BINDER_DEBUG_PRIORITY_CAP = 1U << 13,// 8192BINDER_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, // 1BINDER_DEBUG_OPEN_CLOSE = 1U << 1, // 2BINDER_DEBUG_BUFFER_ALLOC = 1U << 2, // 4BINDER_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
更多framework实战开发,请关注下面“千里马学框架”