原因:
vma已经释放,但其对应的proc结构却未释放
而vma和proc分别是在 binder_vma_close 和 binder_release-> binder_deferred_workqueue中释放的
在main_log中发现:
03-19 15:06:05.842 143 12974 E M4U_L : Open file failed mFileDescriptor=-1, error=24 :Too many open files
03-19 15:06:05.842 143 12974 E M4U_L : m4u_alloc_mva failed
这样怀疑是文件打开过多,导致m4u要打开/dev/M4U_device进行mmap出错,然后mediaserver退出
但即使mediaserver退出,binder驱动也应该同步释放其对应的 proc结构啊!
于是怀疑是不是在文件打开过多的情况下就会这一问题,验证:
先在一个拥有binder服务的进程中打开多个文件(一般最多可以打开1024+3, 1024可用ulimit -a查看, 3是三个标准输入输出),然后再kill掉此进程,结果重现:
kernel log中对pid=131也确实只调用释放了vma,没有释放proc(binder_release)
T:\W\a\P1227T_1.14.2\o\t\p\b89_c_j2\system\bin> adb shell cat /proc/kmsg |egrep "vma|binder_release"
<6>[ 45.091496] (0)[1737:Binder_1]binder: 1727 close vm area 5d12c000-5d32a000 (2040 K) vma 2220051 pagep 79f
<6>[ 45.091793] (1)[44:kworker/u:1]binder_release: 1727: page 0 at e6e00000 not freed
<6>[ 45.091894] (1)[44:kworker/u:1]binder_release: 1727 threads 4, nodes 2 (ref 2), refs 8, active transactions 0, buffers 0, pages 1
<6>[ 95.385043] (0)[2003:MyClient]binder: 2003 close vm area 401aa000-403a8000 (2040 K) vma 2220051 pagep 79f
<6>[ 95.385316] (0)[5:kworker/u:0]binder_release: 2003: page 0 at e0c00000 not freed
<6>[ 95.385392] (0)[5:kworker/u:0]binder_release: 2003 threads 1, nodes 0 (ref 0), refs 2, active transactions 0, buffers 1, pages 1
<6>[ 136.355312] (0)[176:Binder_1]binder: 131 close vm area 4081c000-40a1a000 (2040 K) vma 2220051 pagep 79f
<6>[ 136.373461] (0)[2019:vivo_daemon]binder_mmap: 2019 4068a000-40888000 (2040 K) vma 200071 pagep 79f
同时,在系统中已经不存在pid=131的进程,但其binder/proc却仍然存在:
F:\WD\eclipse\bin\release>adb shell ps 131
USER PID PPID VSIZE RSS WCHAN PC NAME
F:\WD\eclipse\bin\release>adb shell cat /mnt/binder/proc/131
binder proc state:
proc 131
thread 131: l 22
thread 176: l 22
node 5 (vivo_daemon.service): u4031b8a8 c4031b88c hs 1 hw 1 ls 0 lw 0 is 0 iw 0
ref 3: desc 0 node 1 s 1 w 1 d (null)
node work 5: u4031b8a8 c4031b88c
ps.奇怪的是,在上述vivo_daemon自动重启后,重复这一操作,proc和vma则都能正常销毁,可以是与131已经存在于binder驱动中有关,这个要后面深入binder驱动才能解释。