背景:
經常有學員朋友在做系統開發時候,有時候遇到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實戰開發,請關注下面“千里馬學框架”