當前位置：首頁 > 运维知识 > Android >内容正文

Android

Android Binder Driver缺陷导致定屏问题分析

發(fā)布時間：2025/3/15 Android 55 豆豆

生活随笔收集整理的這篇文章主要介紹了 Android Binder Driver缺陷导致定屏问题分析小編覺得挺不錯的,現(xiàn)在分享給大家,幫大家做個參考.

本文講解異步Android binder call是如何阻塞整個系統(tǒng)的，通過ramdump信息以及binder通信協(xié)議來演繹并還原定屏現(xiàn)場。

一、背景知識點

解決此問題所涉及到的基礎(chǔ)知識點有：Trace、CPU調(diào)度、Ramdump推導、Crash工具、GDB工具、Ftrace，尤其深入理解binder IPC機制。

1.1 工具簡介

Trace：分析死鎖問題的最基本的技能，通過kill -3可生成相應(yīng)的traces.txt文件，里面記錄著當前時刻系統(tǒng)各線程所處在的調(diào)用棧。
CPU調(diào)度：可通過查看schedstat節(jié)點，得知該線程是否長時間處于RQ隊列的等待
Ramdump：把系統(tǒng)memory中某一個時間點的數(shù)據(jù)信息保存起來的內(nèi)存崩潰文件，屬于ELF文件格式。當系統(tǒng)發(fā)生致命錯誤無法恢復的時候，主動觸發(fā)抓取ramdump能異常現(xiàn)場保留下來，這是屬于高級調(diào)試秘籍。
Crash工具：用于推導與分析ramdump內(nèi)存信息。
GDB工具：由GNU開源組織發(fā)布的、UNIX/LINUX操作系統(tǒng)下的基于命令行的強大調(diào)試工具，比如用于分析coredump
Ftrace：用于分析Linux內(nèi)核的運行時行為的強有力工具，比如能某方法的耗時數(shù)據(jù)、代碼的執(zhí)行流情況。

1.2 Binder簡介

Binder IPC是最為整個Android系統(tǒng)跨進程通信的基石，整個系統(tǒng)絕大多數(shù)的跨進程都是采用Binder，如果對Binder不太了解看本文會非常吃力，在Gityuan.com博客中有大量講解關(guān)于Binder原理的文章，見http://gityuan.com/2015/10/31/binder-prepare/。這里不再贅述，簡單列兩張關(guān)于Binder通信架構(gòu)的圖。

Binder通信采用C/S架構(gòu)，主要包含Client、Server、ServiceManager以及binder驅(qū)動部分，其中ServiceManager用于管理系統(tǒng)中的各種服務(wù)。Client向Server通信過程圖中畫的是虛線，是由于它們彼此之間不是直接交互的，而是采用ioctl的方式跟Binder驅(qū)動進行交互的，從而實現(xiàn)IPC通信方式。

接下來再以startService為例，展示一次Binder通信過程的方法執(zhí)行流:

從圖中，可見當一次binder call發(fā)起后便停在waitForResponse()方法，等待執(zhí)行完具體工作后才能結(jié)束。那么什么時機binder call端會退出waitForResponse()方法？見下圖：

退出waitForResponse場景說明：

1）當Client收到BR_DEAD_REPLY或BR_FAILED_REPLY(往往是對端進程被殺或者transaction執(zhí)行失敗)，則無論是同步還是異步的binder call都會結(jié)束waitForResponse()方法。
2）正常通信的情況下，當收到BR_TRANSACTION_COMPLETE則結(jié)束同步binder call；當收到BR_REPLY則結(jié)束異步binder call。

二、初步分析

有了以上背景知識的鋪墊，接下來就進入正式實戰(zhàn)分析過程。

2.1 問題描述

Android 8.0系統(tǒng)用幾十臺手機連續(xù)跑幾十個小時Monkey的情況下有概率出現(xiàn)定屏問題。

定屏是指屏幕長時間卡住不動，也可以成為凍屏或者hang機，絕大多數(shù)情況下都是由于多個線程之間存在直接或者間接死鎖而引發(fā)，而本案例實屬非常罕見例子，異步方法處于無限等待狀態(tài)被blocked，從而導致的定屏。

2.2 初步分析

通過查看trace，不難發(fā)現(xiàn)導致定屏的原因如下：

system_server的所有binder線程以及其中重要現(xiàn)場都在等待AMS鎖，而AMS鎖被線程Binder:12635_C所持有； Binder:12635_C線程正在執(zhí)行bindApplication()方法，調(diào)用棧如下：

終極難題：attachApplicationLocked()是屬于異步binder call，之所以叫異步binder call，就是由于可異步執(zhí)行而并不會阻塞線程。但此處卻能阻塞整個系統(tǒng)，這一點基本是毀三觀的地方。

懷疑1：有同學可能會覺得是不是Binder驅(qū)動里的休眠喚醒問題，對端進程出現(xiàn)異常導致無法喚醒該binder線程從而阻塞系統(tǒng)？?
回答1：這個觀點咋一看，好像合情合理，還挺能唬人的。接下來，我先來科普一下，以正視聽。

如果熟悉Binder原理的同學，應(yīng)該知道上面說的是不可能發(fā)生的事情。oneway binder call，也就是所謂的異步調(diào)用， Binder機制設(shè)計絕不可能傻到讓異步的binder call來需要等待對端進程的喚醒。

真正的oneway binder call，一旦是事務(wù)發(fā)送出去。 a)如果成功，則會向自己線程thread->todo隊列里面放上BINDER_WORK_TRANSACTION_COMPLETE; b)如果失敗，則會向自己線程thread->todo隊列里面放上BINDER_WORK_RETURN_ERROR。

緊接著，就會在binder_thread_read()過程把剛才的BINDER_WORK_XXX讀取出去，然后調(diào)出此次binder call。之所以要往自己隊列放入BINDER_WORK_XXX，為了告知本次事務(wù)是否成功的投遞到對端進程。但整個過程，無需對端進程的參與。

也就是說bindApplication()方法作為異步binder調(diào)用方法，只會等待自己向自己todo隊列寫入的BR_TRANSACTION_COMPLETE或BR_DEAD_REPLY或BR_FAILED_REPLY。

所以說，對端進程無法喚醒的說法是絕無可能的猜想。

懷疑2：CPU的優(yōu)先級反轉(zhuǎn)問題，當前Binder線程處于低優(yōu)先級，無法分配到CPU資源而阻塞系統(tǒng)？?
回答2：從bugreport中來分析定屏過程被阻塞線程的cpu調(diào)度情況。

先講解之前，先來補充一點關(guān)于CPU解讀技巧：

nice值越小則優(yōu)先級越高。此處nice=-2, 可見優(yōu)先級還是比較高的;

schedstat括號中的3個數(shù)字依次是Running、Runable、Switch，緊接著的是utm和stm

Running時間：CPU運行的時間，單位ns
Runable時間：RQ隊列的等待時間，單位ns
Switch次數(shù)：CPU調(diào)度切換次數(shù)
utm: 該線程在用戶態(tài)所執(zhí)行的時間，單位是jiffies，jiffies定義為sysconf(_SC_CLK_TCK)，默認等于10ms
stm: 該線程在內(nèi)核態(tài)所執(zhí)行的時間，單位是jiffies，默認等于10ms

可見，該線程Running=186667489018ns,也約等于186667ms。在CPU運行時間包括用戶態(tài)(utm)和內(nèi)核態(tài)(stm)。 utm + stm = (12112 + 6554) ×10 ms = 186666ms。

結(jié)論：utm + stm = schedstat第一個參數(shù)值。

有了以上基礎(chǔ)知識，再來看bugreport，由于系統(tǒng)被hang住，watchdog每過一分鐘就會輸出依次調(diào)用棧。我們把每一次調(diào)用找的schedstat數(shù)據(jù)拿出來看一下，如下：

可見，Runable時間基本沒有變化，也就說明該線程并沒有處于CPU等待隊列而得不到CPU調(diào)度，同時Running時間也幾乎沒有動。所以該線程長時間處于非Runable狀態(tài)，從而排除CPU優(yōu)先級反轉(zhuǎn)問題。

再看Event Log

01-19 19:02:33.668 12635 24699 I am_proc_start: [0,6686,10058,com.xxx.calculator,activity,com.xxx.calculator/.convert.ConvertActivity] 01-19 19:02:33.840 12635 12846 I am_kill : [0,6686,com.xxx.calculator,-10000,remove task] 01-19 19:02:33.911 12635 13399 I am_proc_bound: [0,6686,com.xxx.calculator] 01-19 19:02:33.913 12635 13399 I am_proc_died: [0,6686,com.xxx.calculator,18]

疑問：appDiedLock()方法一般是通過BinderDied死亡回調(diào)的情況下才執(zhí)行，但死亡回調(diào)肯定是位于其他線程，由于該binder線程正處于繁忙狀態(tài)，并沒有時間處理。為什么同一個線程正在執(zhí)行attachApplication()的過程，并沒有結(jié)束的情況下還能執(zhí)行appDiedLock()方法？

觀察多份定屏的EventLog，最后時刻都會先執(zhí)行attachApplication()，然后執(zhí)行appDiedLock()。此處懷疑跟殺進程有關(guān)，或者是在某種Binder嵌套調(diào)用的情況下，將這兩件事情合在binder線程？這些都只是猜疑，本身又是概率問題，需要更深入地分析才能解答這些疑團。

三、ramdump分析

有效的信息太少，基本無法采用進一步分析，只能通過抓取ramdump希望能通過里面的蛛絲馬跡來推出整個過程。

抓取的ramdump是只是觸發(fā)定屏后的最后一刻的異常現(xiàn)場，這就好比犯罪現(xiàn)場最后的畫面，我們無法得知案發(fā)的動機是什么，更無法得知中間到底發(fā)生了哪些狀態(tài)。要基于ramdump的靜態(tài)畫面，去推演整個作案過程，需要強大的推演能力。先來分析這個ramdump信息，找到盡可能多的有效信息。

3.1 結(jié)構(gòu)體binder_thread

從ramdump中找到當前處于blocked線程的調(diào)用棧上的方法binder_ioctl_write_read()，該方法的的第4個參數(shù)指向binder_read結(jié)構(gòu)體，采用crash工具便可進一步找到binder_thread的結(jié)構(gòu)體如下：

解讀：

waiting_thread_node為空，則說明binder線程的 thread→transaction_stack不為空或者 thread→todo不為空；
todo為空，結(jié)合前面的waiting_thread_node，則說明thread→transaction_stack一定不為空；
return_error和reply_error的cmd等于29185，轉(zhuǎn)換為16進制等于0x7201, 代表的命令為BR_OK = _IO(‘r’, 1), 說明該binder線程的終態(tài)并沒有error，或者中間發(fā)生error并且已被消耗掉；
looper = 17, 說明該線程處于等待狀態(tài)BINDER_LOOPER_STATE_WAITING

3.2 binder_transaction結(jié)構(gòu)體

既然thread→transaction_stack不為空，根據(jù)結(jié)構(gòu)體binder_thread的成員transaction_stack = 0xffffffddf1538180，則解析出binder_transaction結(jié)構(gòu)體

解讀：

from = 0x0, 說明發(fā)起端進程已死
sender_euid=10058，這里正是event log中出現(xiàn)的被一鍵清理所殺的進程，這里隱約能感受到此次異常跟殺進程有關(guān)
to_thread所指向的是當前system_server的binder線程，說明這是遠端進程向該進程發(fā)起的請求
flags = 16, 說明是同步binder call
code = 11，說明該調(diào)用attachApplication()，此處雖無法完成確定，但從上下文以及前面的stack，基本可以這么認為，后續(xù)會論證。

到這里，想到把binder接口下的信息也拿出來，看看跟前面基本是吻合的code=b, 也應(yīng)該是attachApplication(), 如下：

thread 13399: l 11 need_return 0 tr 0 incoming transaction 2845163: ffffffddf1538180 from 0:0 to 12635:13399 code b flags 10 pri 0:120 r1 node 466186 size 92:8 data ffffff8014202c98

3.3 特殊的2916

看一下kernel Log，被hang住的binder線程有一個Binder通信失敗的信息：

binder : release 6686:6686 transaction 2845163 out, still active binder : 12635:13399 transaction failed 29189/-22, size 3812-24 line 2916

29189=0x7205代表的是BR_DEAD_REPLY = _IO(‘r’, 5), 則代表return_error=BR_DEAD_REPLY，發(fā)生錯誤行是2916，什么場景下代碼會走到2916行呢，來看Binder Driver的代碼：

根據(jù)return_error=BR_DEAD_REPLY，從2916往回看則推測代碼應(yīng)該是走到2908行代碼；往上推說明target_node = context→binder_context_mgr_node，這個target_node是指service_manager進程的binder_node。那么binder_context_mgr_node為空的場景，只有觸發(fā)servicemanger進程死亡，或者至少重啟過；但通過查看servicemanger進程并沒有死亡和重啟；本身走到2900行， tr->target.handle等于空，在這個上下文里面就難以解釋了，現(xiàn)在這個來看更是矛盾。

到此，不得不懷疑推理存在紕漏，甚至懷疑日志輸出機制。經(jīng)過反復驗證，才發(fā)現(xiàn)原來忽略了2893行的binder_get_node_refs_for_txn()，代碼如下：

一切就豁然開朗，由于對端進程被殺，那么note→proc==null, 從而有了return_error=BR_DEAD_REPLY。

3.4 binder_write_read結(jié)構(gòu)體

看完被阻塞的binder線程和事務(wù)結(jié)構(gòu)體，接著需要看一下數(shù)據(jù)情況，調(diào)用棧上的binder_ioctl_write_read()方法的第三個參數(shù)便指向binder_write_read結(jié)構(gòu)體，用crash工具解析后，得到如下信息：

解讀：

write_size=0, 看起來有些特別，本次通信過程不需要往Binder Driver寫數(shù)據(jù)，常規(guī)transaction都有命令需寫入Binder Driver；
read_size=256，本次通信過程需要讀取數(shù)據(jù)；

那么什么場景下，會出現(xiàn)write_size等于0，而read_size不等于0呢？需要查看用戶空間跟內(nèi)核空間的Binder Driver交互的核心方法talkWithDriver()，代碼如下：

從上述代碼可知：read_size不等于0，則doReceive=true, needRead=true，從而mIn等于空；再加上write_size=0則mOut為空。也就是說該blocked線程最后一次跟Binder驅(qū)動交互時的mIn和mOut都為空。

而目前的線程是卡在attachApplicationLocked()過程，在執(zhí)行該方法的過程一定是會向mOut里面寫入數(shù)據(jù)的。但從案發(fā)后的最后一次現(xiàn)場來看mOut里面的數(shù)據(jù)卻為空，這是違反常規(guī)的操作，第一直覺可能會懷疑是不是出現(xiàn)了內(nèi)存踩踏之類的，但每次都這么湊巧地能只踩踏這個數(shù)據(jù)，是不太可能的事。為了進一步驗證，再把mOut和mIn這兩個buffer的數(shù)據(jù)拿出來。

3.5 mOut && mIn

IPCThreadState結(jié)構(gòu)體在初始化的時候，分別設(shè)置mOut和mIn的size為256。Binder IPC過程便是利用mOut和mIn 分別承擔向Binder驅(qū)動寫數(shù)據(jù)以及從Binder驅(qū)動讀數(shù)據(jù)的功能。雖然在反復使用的過程中會出現(xiàn)老的命令被覆蓋的情況，但還是可能有一些有用信息。

mOut和mIn是用戶空間的數(shù)據(jù)，并且是IPCThreadState對象的成員變量。程序在用戶空間停在IPCThreadState的waitForResponse()過程，采用GDB打印出當前線程用戶空間的this指針的所有成員，即可找到mOut和mIn

解讀： mIn緩存區(qū)，mDataSize = 16, mDataPos = 16, 說明最后的talkWithDriver產(chǎn)生了兩個BR命令，并且已處理；mOut緩存區(qū)，mDataSize = 0, mDataPos = 0，說明BC_XXX都已被消耗

再來進一步看看這兩個緩存區(qū)中的數(shù)據(jù)，從上圖可知mIn和mOut的mData地址分別為0x7747500300、0x7747500400，緩存區(qū)大小都等于256字節(jié)； mIn緩存區(qū)中存放都是BR_XXX命令(0x72)；mOut緩存區(qū)中存放都是BC_XXX命令(0x63)。再來分別看看兩個緩存區(qū)中的數(shù)據(jù)：

mIn緩存區(qū)數(shù)據(jù)：

解讀：BR_NOOP = 0x720c, BR_CLEAR_DEATH_NOTIFICATION_DONE = 0x7210，可知mIn數(shù)據(jù)區(qū)中最后一次talkWithDriver的過程產(chǎn)生了兩個BR命令依次是： BR_NOOP， BR_CLEAR_DEATH_NOTIFICATION_DONE

mOut緩存區(qū)數(shù)據(jù)：

解讀：BC_FREE_BUFFER = 0x6303, BC_DEAD_BINDER_DONE = 0x6310，可知mOut數(shù)據(jù)區(qū)最后一次talkWithDriver的過程，所消耗掉的BC命令依次是：BC_FREE_BUFFER, BC_DEAD_BINDER_DONE

分析兩份ramdump里面的mOut和mIn數(shù)據(jù)區(qū)內(nèi)容內(nèi)容基本完全一致，緩存區(qū)中的BC和BR信息完全一致。整個過程，通過ramdump推導發(fā)現(xiàn)被阻塞線程的todo隊列居然為空，最后一次處理過的transaction是BC_FREE_BUFFER、BC_DEAD_BINDER_DONE和BR_NOOP、BR_CLEAR_DEATH_NOTIFICATION_DONE，能解讀出來對本案例有所關(guān)聯(lián)線索也就只有這么多。

3.6 疑難懸案

解決系統(tǒng)疑難問題可能不亞于去案件偵破，而本案就好比是密室殺人案。案發(fā)后第一時間去勘察現(xiàn)場(抓取ramdump)，從房門和窗口都是由內(nèi)部緊鎖的(mIn緩存區(qū)的write_size等于0)，兇手作案后是如何逃離現(xiàn)場的(todo隊列為空)？從被害人(blocked線程)身體留下的劍傷并不會致命(異步線程不會被阻塞)，那到底死因是什么呢？從現(xiàn)場種種跡象來看(ramdump推導)很有可能是這并非第一案發(fā)現(xiàn)場(BUG不是發(fā)現(xiàn)在當前binder transaction過程)，極有可能是兇手在它處作案(其他transaction)后，再移尸到當前案發(fā)現(xiàn)場(binder嵌套結(jié)束后回到上一級調(diào)用處)，那么真正的第一案發(fā)現(xiàn)場又在哪里呢？這些都匪夷所思。

Trace、Log、Ramdump推導、Crash工具、GDB工具等十八般武藝都用過一輪了，已經(jīng)沒有更多的信息可以挖掘了，快沒有頭緒了，這個問題幾乎要成為無頭公案。

四、真相大白

4.1 案件偵破

此案一日不破，有如鯁在噎，寢食難安。腦中反復回放案發(fā)現(xiàn)場的周邊布置，有一個非常重大的疑點進入腦海，其中有一個物件（BC_DEAD_BINDER_DONE協(xié)議)正常應(yīng)該在其他房間(binder死亡訃告相關(guān))，可為何會出現(xiàn)在案發(fā)現(xiàn)場(bindApplication的waitForResponse過程)呢？

基于最后的現(xiàn)場，順著這個線索通過逆向推理分析，去試圖推演兇手的整個作案過程。但對于如此錯終復雜的案情(binder通信系統(tǒng)每時每刻都有大量的事transaction發(fā)生著，協(xié)議之間的轉(zhuǎn)換也比較復雜)，僅憑一兩個協(xié)議來逆向回推案發(fā)現(xiàn)場是如何一步步演化幾乎是不太可能的事。跟同事一起討論，通過不斷逆向與正向結(jié)合分析，每一層逆向回推，都會有N種可能性，通過不斷排除其他的可能性，盡可能多地排除完全不可能的分支，保留可能的分支再繼續(xù)回推，最終奇跡般地找到了第一案發(fā)現(xiàn)場，也找到了復現(xiàn)方法。

這個逆向推理過程非常復雜，首先需要深入掌握Binder原理，在整個推演過程最為燒腦與費時。為了節(jié)省篇幅，此處省略一萬字。

直接拿出結(jié)論，真正的第一案發(fā)現(xiàn)場如下：在進程剛啟動不久，執(zhí)行到linkToDeath()方法前的瞬間將其殺掉則能復現(xiàn)定屏：

4.2 案卷解讀

這個問題的復雜在于，即便找到了第一個案發(fā)現(xiàn)場以及復現(xiàn)路徑，要完全理解中間的每一次協(xié)議轉(zhuǎn)換過程，也是比較復雜的。通過如下命令打開binder driver的ftrace信息，用于輸出每次binder通信協(xié)議與數(shù)據(jù)。

整個binder通信會不斷地在用戶空間與內(nèi)核空間之間進行切換, Binder IPC通信過程的數(shù)據(jù)流向說明：（ BINDER_WORK_XXX簡稱為BW_XXX）

mOut：記錄用戶空間向Binder Driver寫入的命令
- 通過binder_thread_write()和binder_transaction()方法消費BC命令，并產(chǎn)生相應(yīng)的BW_XXX命令，也可能不產(chǎn)生BW命令
- 當thread->return_error.cmd != BR_OK，則不會執(zhí)行binder_thread_write()過程
thread→todo: 記錄等待當前binder線程需要處理的BINDER_WORK
- 通過binder_thread_read()方法消費BW命令，并生產(chǎn)相應(yīng)的BR_XX命令，也可能不產(chǎn)生BR命令
- 一般情況，沒有BC_TRANSACION或者BC_REPLY，則不讀取; BW_DEAD_BINDER例外；
mIn: 記錄Binder Driver傳到用戶空間的命令
- 通過waitForResponse()和executeCommand()方法消費BR命令

另外，關(guān)于talkWithDriver, 當mIn有數(shù)據(jù)，意味著先不需要從binder driver讀數(shù)據(jù)。原因：needRead=0，則read_buffer size設(shè)置為0，當doReceive=true，則write_buffer size也設(shè)置為0。從而此次不會跟driver交互。

以下是一次定屏復現(xiàn)過程吐出的ftrace信息：

Binder:1885_5-2351 [002] ...1 242.804499: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce6928 Binder:1885_5-2351 [002] ...1 242.804503: binder_command: cmd=0x40046304 BC_INCREFS Binder:1885_5-2351 [002] ...1 242.804515: binder_command: cmd=0x40046305 BC_ACQUIRE Binder:1885_5-2351 [002] ...1 242.804517: binder_command: cmd=0x400c630e BC_REQUEST_DEATH_NOTIFICATION Binder:1885_5-2351 [002] ...1 242.804524: binder_write_done: ret=0 Binder:1885_5-2351 [002] ...1 242.804526: binder_ioctl_done: ret=0Binder:1885_5-2351 [003] ...1 242.854847: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce4f18 Binder:1885_5-2351 [003] ...1 242.854852: binder_command: cmd=0x40406300 BC_TRANSACTION // bindApplication()， Binder:1885_5-2351 [003] ...1 242.854900: binder_write_done: ret=0 Binder:1885_5-2351 [003] ...1 242.854902: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=1 //binder_thread_read（）處理BINDER_WORK_DEAD_BINDER，生成BR_DEAD_BINDER Binder:1885_5-2351 [003] ...1 242.854905: binder_return: cmd=0x8008720f BR_DEAD_BINDER Binder:1885_5-2351 [003] ...1 242.854906: binder_read_done: ret=0 Binder:1885_5-2351 [003] ...1 242.854908: binder_ioctl_done: ret=0Binder:1885_5-2351 [003] ...1 242.854920: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce4d58 //既有可能是thread->return_error.cmd ！= BR_OK Binder:1885_5-2351 [003] ...1 242.854922: binder_write_done: ret=0 Binder:1885_5-2351 [003] ...1 242.854923: binder_ioctl_done: ret=0Binder:1885_5-2351 [003] ...1 242.863203: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce1c08 Binder:1885_5-2351 [003] ...1 242.863258: binder_write_done: ret=0 Binder:1885_5-2351 [003] ...1 242.863263: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=1 //取出BINDER_WORK_RETURN_ERROR， BR_DEAD_REPLY，此次炸死。BR_TRANSACTION_COMPLETE僅僅是打印錯誤 Binder:1885_5-2351 [003] ...1 242.863272: binder_return: cmd=0x7206 BR_TRANSACTION_COMPLETE Binder:1885_5-2351 [003] ...1 242.863276: binder_read_done: ret=0 Binder:1885_5-2351 [003] ...1 242.863279: binder_ioctl_done: ret=0// sendObituary（） Binder:1885_5-2351 [003] ...1 242.868356: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce31a8 Binder:1885_5-2351 [003] ...1 242.868392: binder_command: cmd=0x400c630f BC_CLEAR_DEATH_NOTIFICATION //雷被拿了，return_error=BR_Ok才可以寫；將death->work.type由BINDER_WORK_DEAD_BINDER改為 BINDER_WORK_DEAD_BINDER_AND_CLEAR。 Binder:1885_5-2351 [003] ...1 242.868403: binder_command: cmd=0x40406300 BC_TRANSACTION //（同步） Binder:1885_5-2351 [003] ...1 242.868707: binder_transaction: transaction=187839 dest_node=14103 dest_proc=2198 dest_thread=0 reply=0 flags=0x11 code=0x1f Binder:1885_5-2351 [003] ...1 242.868734: binder_transaction_alloc_buf: transaction=187839 data_size=96 offsets_size=0 Binder:1885_5-2351 [003] ...1 242.868786: binder_command: cmd=0x40406300 BC_TRANSACTION //（異步） Binder:1885_5-2351 [003] ...1 242.868802: binder_transaction: transaction=187840 dest_node=563 dest_proc=746 dest_thread=0 reply=0 flags=0x10 code=0x8 Binder:1885_5-2351 [003] ...1 242.868807: binder_transaction_alloc_buf: transaction=187840 data_size=1952 offsets_size=112 Binder:1885_5-2351 [003] ...2 242.868822: binder_transaction_ref_to_node: transaction=187840 node=37276 src_ref=37277 src_desc=940 ==> dest_ptr=0x00000079ba160780 Binder:1885_5-2351 [003] ...2 242.868829: binder_transaction_ref_to_node: transaction=187840 node=158140 src_ref=158141 src_desc=116 ==> dest_ptr=0x00000079ba03f6c0 Binder:1885_5-2351 [003] ...2 242.868833: binder_transaction_ref_to_node: transaction=187840 node=8192 src_ref=8193 src_desc=110 ==> dest_ptr=0x00000079bc81b220 Binder:1885_5-2351 [003] ...2 242.868837: binder_transaction_ref_to_node: transaction=187840 node=18544 src_ref=18545 src_desc=416 ==> dest_ptr=0x00000079ba1dbd20 Binder:1885_5-2351 [003] ...2 242.868839: binder_transaction_ref_to_node: transaction=187840 node=8192 src_ref=8193 src_desc=110 ==> dest_ptr=0x00000079bc81b220 Binder:1885_5-2351 [003] ...2 242.868842: binder_transaction_ref_to_node: transaction=187840 node=18659 src_ref=18660 src_desc=420 ==> dest_ptr=0x00000079bd0b3720 Binder:1885_5-2351 [003] ...2 242.868844: binder_transaction_ref_to_node: transaction=187840 node=8192 src_ref=8193 src_desc=110 ==> dest_ptr=0x00000079bc81b220 Binder:1885_5-2351 [003] ...2 242.868847: binder_transaction_ref_to_node: transaction=187840 node=18719 src_ref=18720 src_desc=423 ==> dest_ptr=0x00000079bd0b4120 Binder:1885_5-2351 [003] ...2 242.868849: binder_transaction_ref_to_node: transaction=187840 node=8192 src_ref=8193 src_desc=110 ==> dest_ptr=0x00000079bc81b220 Binder:1885_5-2351 [003] ...2 242.868852: binder_transaction_ref_to_node: transaction=187840 node=18919 src_ref=18920 src_desc=431 ==> dest_ptr=0x00000079ba1ba320 Binder:1885_5-2351 [003] ...2 242.868854: binder_transaction_ref_to_node: transaction=187840 node=8192 src_ref=8193 src_desc=110 ==> dest_ptr=0x00000079bc81b220 Binder:1885_5-2351 [003] ...2 242.868857: binder_transaction_ref_to_node: transaction=187840 node=18785 src_ref=18786 src_desc=425 ==> dest_ptr=0x00000079bd0b4a20 Binder:1885_5-2351 [003] ...2 242.868863: binder_transaction_ref_to_node: transaction=187840 node=130076 src_ref=130077 src_desc=1405 ==> dest_ptr=0x00000079ba03f060 Binder:1885_5-2351 [003] ...2 242.868867: binder_transaction_ref_to_node: transaction=187840 node=159857 src_ref=159858 src_desc=154 ==> dest_ptr=0x00000079ba160c40 Binder:1885_5-2351 [000] ...1 242.869114: binder_write_done: ret=0 Binder:1885_5-2351 [000] ...1 242.869117: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=1 Binder:1885_5-2351 [000] ...1 242.869120: binder_return: cmd=0x7206 BR_TRANSACTION_COMPLETE Binder:1885_5-2351 [000] ...1 242.869122: binder_return: cmd=0x7206 BR_TRANSACTION_COMPLETE Binder:1885_5-2351 [000] ...1 242.869124: binder_read_done: ret=0 Binder:1885_5-2351 [000] ...1 242.869126: binder_ioctl_done: ret=0Binder:1885_5-2351 [000] ...1 242.869137: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce31a8 Binder:1885_5-2351 [000] ...1 242.869140: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=0 Binder:1885_5-2351 [000] ...1 242.869195: binder_transaction_received: transaction=187841 Binder:1885_5-2351 [000] ...1 242.869198: binder_return: cmd=0x80407203 BR_REPLY Binder:1885_5-2351 [000] ...1 242.869202: binder_read_done: ret=0 Binder:1885_5-2351 [000] ...1 242.869203: binder_ioctl_done: ret=0Binder:1885_5-2351 [000] ...1 242.873656: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce1e98 Binder:1885_5-2351 [000] ...1 242.873664: binder_command: cmd=0x40086303 BC_FREE_BUFFER Binder:1885_5-2351 [000] ...1 242.873668: binder_transaction_buffer_release: transaction=187841 data_size=0 offsets_size=0 Binder:1885_5-2351 [000] ...1 242.873671: binder_command: cmd=0x40406300 BC_TRANSACTION Binder:1885_5-2351 [000] ...1 242.873784: binder_transaction: transaction=187849 dest_node=127265 dest_proc=5730 dest_thread=0 reply=0 flags=0x11 code=0x31 Binder:1885_5-2351 [000] ...1 242.873787: binder_transaction_alloc_buf: transaction=187849 data_size=76 offsets_size=0 Binder:1885_5-2351 [000] ...1 242.873814: binder_write_done: ret=0 Binder:1885_5-2351 [000] ...1 242.873816: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=1 Binder:1885_5-2351 [000] ...1 242.873820: binder_return: cmd=0x7206 BR_TRANSACTION_COMPLETE Binder:1885_5-2351 [000] ...1 242.873821: binder_read_done: ret=0 Binder:1885_5-2351 [000] ...1 242.873823: binder_ioctl_done: ret=0Binder:1885_5-2351 [000] ...1 242.876271: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce1e98 Binder:1885_5-2351 [000] ...1 242.876302: binder_command: cmd=0x40406300 BC_TRANSACTION Binder:1885_5-2351 [000] ...1 242.876417: binder_transaction: transaction=187850 dest_node=23725 dest_proc=3051 dest_thread=0 reply=0 flags=0x11 code=0x31 Binder:1885_5-2351 [000] ...1 242.876423: binder_transaction_alloc_buf: transaction=187850 data_size=76 offsets_size=0 Binder:1885_5-2351 [000] ...1 242.876456: binder_write_done: ret=0 Binder:1885_5-2351 [000] ...1 242.876459: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=1 Binder:1885_5-2351 [000] ...1 242.876461: binder_return: cmd=0x7206 BR_TRANSACTION_COMPLETE Binder:1885_5-2351 [000] ...1 242.876463: binder_read_done: ret=0 Binder:1885_5-2351 [000] ...1 242.876464: binder_ioctl_done: ret=0 // sendObituary（）結(jié)束Binder:1885_5-2351 [000] ...1 242.886935: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce4f18 Binder:1885_5-2351 [000] ...1 242.886975: binder_command: cmd=0x40086310 BC_DEAD_BINDER_DONE Binder:1885_5-2351 [000] ...1 242.886980: binder_write_done: ret=0 Binder:1885_5-2351 [000] ...1 242.886984: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=1 Binder:1885_5-2351 [000] ...1 242.886993: binder_return: cmd=0x80087210 BR_CLEAR_DEATH_NOTIFICATION_DONE Binder:1885_5-2351 [000] ...1 242.886996: binder_read_done: ret=0 Binder:1885_5-2351 [000] ...1 242.886999: binder_ioctl_done: ret=0Binder:1885_5-2351 [000] ...1 242.887012: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce4f18 Binder:1885_5-2351 [000] ...1 242.887013: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=0 Binder:1885_5-2351 [000] ...1 260.021887: binder_read_done: ret=-512 Binder:1885_5-2351 [000] ...1 260.021893: binder_ioctl_done: ret=-512 Binder:1885_5-2351 [000] ...1 260.023938: binder_ioctl: cmd=0xc0306201 arg=0x71f6ce4f18 Binder:1885_5-2351 [000] ...1 260.023972: binder_wait_for_work: proc_work=0 transaction_stack=1 thread_todo=0

將以上信息轉(zhuǎn)換為表格形式來展示案發(fā)過程：

以流程圖的方式來展示案發(fā)過程：

過程解讀：

該線程執(zhí)行l(wèi)inkToDeath()，采用flush只寫不讀的方式，向Binder Driver的thread todo隊列寫入BW_DEAD_BINDER；

執(zhí)行bindApplication(), 由于目標進程已死，則寫入BW_RETURN_ERROR到todo隊列，此時return_error.cmd = BR_DEAD_REPLY; 內(nèi)核空間，將BW_DEAD_BINDER轉(zhuǎn)換為BR_DEAD_BINDER，同步將BW_DEAD_BINDER 放入proc->delivered_death; 回到用戶空間，執(zhí)行sendObituary()，此時還處于bindApplication()的waitForResponse()。

向mOut添加BC_CLEAR_DEATH_NOTIFICATION，采用flush方式，加上return_error.cmd = BR_DEAD_REPLY，此次不寫不讀。

執(zhí)行第一個reportOneDeath()，此時return_error.cmd = BR_DEAD_REPLY則不寫入，取出BW_RETURN_ERROR，同時設(shè)置return_error.cmd=BR_OK；回到用戶空間，終結(jié)第一個reportOneDeath()，錯誤地消耗了bindApplication()所產(chǎn)生的BR_DEAD_REPLY。

執(zhí)行第二個reportOneDeath()，同時消耗了第一個和第二個reportOneDeath所產(chǎn)生的BR_TRANSACTION_COMPLETE協(xié)議，由于第二個reportOneDeath是同步binder call, 還需繼續(xù)等待BR_REPLY協(xié)議。

此時mOut和mIn都為空，進入內(nèi)核binder_wait_for_work(),等待目標進程發(fā)起B(yǎng)C_REPLY命令，向當前線程todo隊列放入BW_TRANSACTION；收到BW_TRANSACTION協(xié)議后轉(zhuǎn)換為BR_REPLY，完成第二個reportOneDeath()。

執(zhí)行第三個reportOneDeath()，收到BR_TRANSACTION_COMPLETE后，完成第二個reportOneDeath()。

到此徹底執(zhí)行完sendObituary()，則需向mOut添加BC_DEAD_BINDER_DONE協(xié)議，收到該協(xié)議后，驅(qū)動將proc→delivered_death的BW_DEAD_BINDER_AND_CLEAR調(diào)整為BW_CLEAR_DEATH_NOTIFICATION，并放入thread->todo隊列；然后生成BR_CLEAR_DEATH_NOTIFICATION_DONE，完成本次通信；

回到bindApplication()的waitForResponse，此時mOut和mIn都為空，進入內(nèi)核binder_wait_for_work(), 該線程不再接收其他事務(wù)，也無法產(chǎn)生事務(wù)，則永遠地被卡住。

總結(jié)：整個過程發(fā)生了10次 talkWithDriver()

第一個異步reportOneDeath()消費掉bindApplication()所產(chǎn)生的BW_RETURN_ERROR；
第二個同步reportOneDeath()所消耗掉第一個異步reportOneDeath()自身殘留的BR_TRANSACTION_COMPLETE；
bindApplication()所產(chǎn)生的BW_RETURN_ERROR由于被別人所消費，導致陷入無盡地等待。

4.3 總結(jié)

真正分析遠比這復雜，鑒于篇幅，文章只講解其中一個場景，不同的Binder Driver以及不同的Framework代碼組合有幾種不同的表現(xiàn)與處理流程。不過最本質(zhì)的問題都是在于在嵌套的binder通信過程，BR_DEAD_REPLY錯誤地被其他通信所消耗從而導致的異常。我的解決方案是一旦發(fā)生錯誤，則當BW_RETURN_ERROR事務(wù)放入到當前線程todo隊列頭部，則保證自己產(chǎn)生的BW_RETURN_ERROR事務(wù)一定會被自己所正確地消耗，解決異步binder通信在嵌套場景下的無限阻塞的問題，優(yōu)化后的處理流程圖：

當然還有第二個解決方案就是盡可能避免一切binder嵌套，Google在最新的binder driver驅(qū)動里面采用將BW_DEAD_BINDER放入proc的todo隊列來避免嵌套問題，這個方案本身也OK，但我認為在執(zhí)行過程出現(xiàn)了BW_RETURN_ERROR還是應(yīng)該放到隊列頭部，第一時間處理error，從而也能避免被錯誤消耗的BUG，另外后續(xù)如果binder新增其他邏輯，也有可能會導致嵌套的出現(xiàn)，那么仍然會有類似的問題。最近跟Google工程師來回多次溝通過這個問題，他們?nèi)匀幌Ｍ３置看沃煌鵷hread todo隊列尾部添加事務(wù)的邏輯，對于嵌套問題希望通過將其放入proc todo隊列的方式來解決。對此，我擔心后續(xù)擴展性方面會忽略或者遺忘，又引發(fā)binder嵌套問題，Google工程師表示未來添加新功能，也會杜絕出現(xiàn)嵌套邏輯，保持邏輯與代碼的簡潔。

最后，這個密室殺人案的確是在它處作案(reportOneDeath消費掉bindApplication所產(chǎn)生的BW_RETURN_ERROR)后，再移尸到當前案發(fā)現(xiàn)場(執(zhí)行完BR_DEAD_BINDER后回到bindApplication的waitForRespone方法)，從而導致異步Binder調(diào)用也能被阻塞。

http://gityuan.com/2018/05/12/binder-driver-bug/

總結(jié)

以上是生活随笔為你收集整理的Android Binder Driver缺陷导致定屏问题分析的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯，歡迎將生活随笔推薦給好友。

上一篇：【译】Introduction to S
下一篇：【译】Federated Learnin