MapleStory

从Systrace学习binder kernel 调用过程

一.Systrace简介

从目前使用看来,Systrace主要包含两个部分:
1.手机中Systrace日志打印框架
2.Chrome或其他日志解析工具,能够将上述生成的日志解析成可视化的图形
其精度可以达到ns

每年的GoogleI/O好像都有提及这个方便的工具,具体的用法的官方教程如下:
视频:
https://www.youtube.com/watch?v=Qfo5fdoXrTU&index=10&list=PLWz5rJ2EKKc-odHd6XEaf7ykfsosYyCKp
文字:
https://developer.android.com/studio/profile/systrace.html

二.binder kernel driver

binder是android中ipc通信的主要机制
其原理可以参考gityuan的博客
http://gityuan.com/2015/11/01/binder-driver/
http://gityuan.com/2015/11/02/binder-driver-2/

三.Systrace in binder kernel

Systrace 作为android 性能调优的主要手段在源码中随处可见
如 AMS 中的 Trace.beginTrace
又如 InputDispatcher 中的 ATRACE

想要抓取binder kernel的trace 首先要打开开关
其路径如下:
/sys/kernel/debug/tracing/events/binder/
我们需要将其 enable 置为 1
echo 1 > enable

随后我们可以使用脚本或者android device monitor 抓取 binder kernel driver的日志

一个简单的调用过程如下
其中6834 为 nfc服务的 pid,3412 为 system_server
nfc服务向 ams 发起 binder通信

  • 1.binder 驱动收到 BC_TRANSACTION 的通信请求
    创建binder_transaction 结构体,分配内存,并将通信的数据写入内存
  • 2.binder 驱动唤醒 system_server处理请求,使用 BR_TRANSACTION 的命令作为标识
    system_server从队列中读取通信请求,并将结果写入内存。
  • 3.system_server 发起 BC_REPLY 请求,该请求是 ONEWAY 的
    binder驱动为新的请求分配内存,并将任务加入到目标进程的队列中
  • 4.binder 驱动告知请求端 请求已经完成 BR_TRANSACTION_COMPLETE,并释放内存
  • 5.binder驱动 从任务队列中读取前面 BC_REPLY 的通信任务,向服务端发起 BR_TRANSACTION_COMPLETE的请求
  • 6.请求端处理 BR_REPLY 的请求
    需要注意的是每个cmd工作在那个进程中,以及其前后的调用次序

Systrace 日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
com.android.nfc-6834 ( 6834) [004] ...2 1005.674370: binder_command: cmd=0x40406300 BC_TRANSACTION
com.android.nfc-6834 ( 6834) [004] ...2 1005.674374: binder_transaction: transaction=141734 dest_node=21476 dest_proc=3412 dest_thread=0 reply=0 flags=0x10 code=0x15
com.android.nfc-6834 ( 6834) [004] ...2 1005.674375: binder_transaction_alloc_buf: transaction=141734 data_size=240 offsets_size=0
com.android.nfc-6834 ( 6834) [004] .N.2 1005.674385: binder_write_done: ret=0
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674399: binder_transaction_received: transaction=141734
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674400: binder_return: cmd=0x80407202 BR_TRANSACTION
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674401: binder_read_done: ret=0
Binder:3412_8-4646 ( 3412) [004] ...1 1005.674403: binder_ioctl_done: ret=0
Binder:3412_8-4646 ( 3412) [004] ...1 1005.674621: binder_ioctl: cmd=0xc0306201 arg=0x7be9dd1fa8
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674623: binder_command: cmd=0x40406301 BC_REPLY
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674625: binder_transaction: transaction=141735 dest_node=0 dest_proc=6834 dest_thread=6834 reply=1 flags=0x0 code=0x0
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674627: binder_transaction_alloc_buf: transaction=141735 data_size=328 offsets_size=8
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674633: binder_transaction_fd: transaction=141735 src_fd=276 ==> dest_fd=35
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674634: binder_write_done: ret=0
Binder:3412_8-4646 ( 3412) [004] ...1 1005.674635: binder_wait_for_work: proc_work=0 transaction_stack=0 thread_todo=1
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674636: binder_return: cmd=0x7206 BR_TRANSACTION_COMPLETE
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674637: binder_read_done: ret=0
Binder:3412_8-4646 ( 3412) [004] ...1 1005.674638: binder_ioctl_done: ret=0
Binder:3412_8-4646 ( 3412) [004] ...1 1005.674652: binder_ioctl: cmd=0xc0306201 arg=0x7be9dd21f8
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674653: binder_command: cmd=0x40086303 BC_FREE_BUFFER
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674654: binder_transaction_buffer_release: transaction=141734 data_size=240 offsets_size=0
Binder:3412_8-4646 ( 3412) [004] ...2 1005.674656: binder_write_done: ret=0
Binder:3412_8-4646 ( 3412) [004] ...1 1005.674656: binder_wait_for_work: proc_work=1 transaction_stack=0 thread_todo=0
com.android.nfc-6834 ( 6834) [004] ...1 1005.674672: binder_wait_for_work: proc_work=0 transaction_stack=0 thread_todo=1
com.android.nfc-6834 ( 6834) [004] ...2 1005.674673: binder_return: cmd=0x7206 BR_TRANSACTION_COMPLETE
com.android.nfc-6834 ( 6834) [004] ...2 1005.674674: binder_transaction_received: transaction=141735
com.android.nfc-6834 ( 6834) [004] ...2 1005.674675: binder_return: cmd=0x80407203 BR_REPLY

Comments