reference

This article explains how asynchronous Binder calls block entire systems using ramdump information and the Binder communication protocol to perform and return to the scene.

First, background knowledge points

Basic knowledge of Trace, CPU scheduling, Ramdump derivation, Crash tools, GDB tools, Ftrace, with a deeper understanding of the Binder IPC mechanism.

1.1 Tool Overview

  • Trace. TXT file, which records the call stack of each thread in the system at the current time.

  • CPU scheduling: You can look at the schedstat node to see if the thread has been waiting on an RQ queue for a long time

  • Ramdump: a memory crash file in ELF format that stores data at a point in time in the system memory. When the system encounters a fatal error that cannot be recovered, active fetching ramdump can save the exception on site, which is an advanced debugging trick.

  • Crash tool: used to derive and analyze ramdump memory information.

  • GDB tool: a powerful command-line debugging tool published by the GNU open-source organization for UNIX/LINUX operating systems, such as coredump analysis

  • Ftrace: A powerful tool for analyzing runtime behavior of the Linux kernel, such as time-consuming data for a method, and the flow of code execution.

1.2 introduction of Binder

Binder IPC is the cornerstone of cross-process communication in the Android system. Binder is used in most cross-process communication in the Android system. If you are not familiar with Binder, it will be very difficult to read this article. See http://gityuan.com/2015/10/31/binder-prepare/, go here.

Two simple diagrams of Binder communication architecture,Binder communication uses the C/S architecture and consists of Client, Server, ServiceManager, and Binder driver. The ServiceManager manages various services in the system. The dotted line in the communication between the Client and Server is because they do not directly interact with each other. Instead, they interact with the Binder drivers through IOCTL to achieve IPC communication.

Next, take startService as an example to show the method execution flow of a Binder communication process:

As you can see from the figure, when a Binder call is initiated, it stops in the waitForResponse() method and waits until the specific work is done.

When does the Binder Call end exit the waitForResponse() method? See below:

Exit the waitForResponse scenario description:

  • 1) Binder calls, both synchronous and asynchronous, terminate the waitForResponse() method when the Client receives a BR_DEAD_REPLY or BR_FAILED_REPLY(usually when the peer process is killed or transaction fails).

  • 2) In the case of normal communication, end the binder call synchronization when BR_TRANSACTION_COMPLETE is received; The asynchronous Binder call ends when BR_REPLY is received.

2. Preliminary analysis

With the above background knowledge foreshadowing, then into the formal actual combat analysis process.

2.1 Problem Description

Android 8.0 system with dozens of phones running for dozens of hours Monkey situation has the probability of a fixed screen problem.

Fixed screen refers to the screen being stuck for a long time, which can also become frozen screen or hang machine. In most cases, it is caused by direct or indirect deadlocks between multiple threads. This case is a very rare example, where the asynchronous method is blocked in the infinite waiting state, resulting in the fixed screen.

2.2 Preliminary Analysis

By checking the trace, it is not difficult to find the reasons for the fixed screen as follows:

All binder threads of system_server and their key sites are waiting for AMS locks, which are held by thread binder :12635_C; Binder:12635_C Thread is executing the bindApplication() method with the following call stack:

AttachApplicationLocked () is an asynchronous binder call, called because it can be executed asynchronously without blocking the thread. But this is where you can clog up the whole system, and that’s basically what’s killing you.

Doubt 1: Some students may think that there is a sleep awakening problem in the Binder driver. The peer process is abnormal and cannot wake up the Binder thread, thus blocking the system.

Answer 1: At first glance, this view seems reasonable, but also quite bluffing. Next, I first to popular science, to set the record straight.

Those of you who are familiar with Binder principles know that this is not going to happen. Oneway Binder Calls, also known as asynchronous calls, can never be so stupid as to make an asynchronous binder call wait for the peer process to wake up.

True Oneway Binder Call, once a transaction is sent out. A) If it succeeds, the BINDER_WORK_TRANSACTION_COMPLETE will be added to the thread->todo queue; B) If the thread->todo queue fails, BINDER_WORK_RETURN_ERROR will be added to the thread->todo queue.

BINDER_WORK_XXX is then read from binder_thread_read() and the binder call is called. We put BINDER_WORK_XXX in our queue to tell us whether the transaction was successfully delivered to the peer process. However, the whole process does not require the participation of the peer process.

That is, the bindApplication() method calls the method as an asynchronous binder and only waits for BR_TRANSACTION_COMPLETE or BR_DEAD_REPLY or BR_FAILED_REPLY that it writes to its own TODO queue.

Therefore, it is impossible to guess that the peer process cannot be awakened.

Suspect 2: CPU priority inversion problem, Binder threads are currently at low priority, unable to allocate CPU resources and blocking the system?

Answer 2: Analyze the CPU scheduling of blocked threads during the screen-fixing process from bugreport.

Before we get started, let’s add a few more CPU reading tips:

The smaller the nice value is, the higher the priority is. Here nice=-2, so it’s a higher priority;

The three numbers in the schedstat brackets are Running, Runable and Switch, followed by UTM and STM

  • Running time: indicates the CPU Running time, in ns

  • Runable time: wait time of the RQ queue, in ns

  • Switch times: indicates the number of CPU scheduling switches

  • Utm: time for the thread to execute in user mode, in jiffies. Jiffies are defined as sysconf(_SC_CLK_TCK), and the default value is 10ms

  • STM: the time for the thread to execute in kernel mode, in jiffies. The default value is 10ms

Running=186667489018ns, which is also approximately 186667ms. The CPU runtime includes user mode (UTM) and kernel mode (STM). Utm + STM = (12112 + 6554) ×10 ms = 186666ms.

Conclusion: UTM + STM = schedstat first parameter value.

With that in mind, the bugreport watchdog prints a stack of calls every minute because the system is hung. Let’s pull out the schedstat data for each call, as follows:

The Runable time is almost unchanged, indicating that the thread is not in the CPU waiting queue and cannot be scheduled by the CPU. Meanwhile, the Running time is almost unchanged. So the thread is in a non-runable state for a long time, eliminating CPU priority inversion.

Look at the Event Log

Question: The appDiedLock() method is usually executed in the case of a BinderDied callback, but the death callback must be in another thread because the binder thread is busy and doesn’t have time to process it. Why can appDiedLock() be used when attachApplication() is still pending in the same thread?

In multiple eventlogs, attachApplication() and appDiedLock() are executed at the end.

Does it have something to do with the kill process or with some kind of Binder nested call, combining the two things with the Binder thread? These are just suspicions, and in themselves questions of probability, which require further analysis to answer.

Iii. Ramdump analysis

There is too little effective information for further analysis. We can only extract the clues in Ramdump to deduce the whole process.

The ramdump captured is just the last abnormal scene after the fixed screen is triggered. It is just like the last scene of the crime scene. We cannot know what the motive of the crime is, let alone what happened in the middle. To deduce the entire crime process based on the static images of Ramdump requires a strong deductive ability. Start by analyzing the ramdump information to find as much valid information as possible.

3.1 Structure binder_thread

From ramdump, find the method binder_ioctl_write_read() on the call stack of the currently blocked thread, whose fourth argument points to the binder_read structure.

The structure of binder_thread can be found as follows:

Reading:

  • If waiting_thread_node is null, thread→transaction_stack or thread→todo is null for binder threads.

  • If thread→transaction_stack is not empty, thread→transaction_stack is not empty.

  • The CMD for return_error and reply_error is 29185, translated into hexadecimal 0x7201, representing the command BR_OK = _IO(‘ r ‘, 1), indicating that the binder thread has no error in its final state. Or an error occurs and has been consumed;

  • If looper is 17, the thread is in the waiting state BINDER_LOOPER_STATE_WAITING

3.2 Binder_transaction structure

Transaction_stack = 0xffffFFDDf1538180; transaction_stack = 0xffffFFDDf1538180; transaction_stack = 0xffffFFDDf1538180;

Reading:

  • From = 0x0, the initiator process is dead

  • Sender_euid =10058, here is exactly the process that appears in the event log to be killed by one-click clearing, here can vaguely feel that this exception is related to the killing process

  • To_thread points to the binder thread of the current System_server, indicating that this is a request from the remote process

  • Flags = 16 indicates that binder call is synchronized

  • AttachApplication () = 11, which indicates that attacplication () is used in the stack.

B = attachApplication(), which is similar to 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 ffffff8014202c98Copy the code

3.3 Special 2916

If you look at the kernel Log, the binder thread that is hung has a message indicating a binder communication failure:

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

29189=0x7205 represents BR_DEAD_REPLY = _IO(‘ r ‘, 5), then represents return_error=BR_DEAD_REPLY. The error line is 2916. Binder Driver code

Based on return_error=BR_DEAD_REPLY, if you look back from 2916, the code should be 2908 lines; Target_node = context→binder_context_mgr_node specifies the binder_node of the service_manager process. If binder_context_mgr_node is empty, only the servicemanger process is triggered to die or at least restarted. The Servicemanger process does not die and restart. Tr ->target.handle = null in line 2900, which is unexplainable in this context, and even more contradictory in this case.

At this point, you have to suspect that the reasoning is flawed, and even suspect the log output mechanism. Line 2893: binder_get_node_refs_for_txn()

Note →proc==null and return_error=BR_DEAD_REPLY.

3.4 Binder_write_read structure

Binder_ioctl_write_read () = binder_write_read () = binder_write_read () = binder_write_read ();

Reading:

  • Write_size =0. This communication does not need to write data to the Binder Driver, as commands are written to the Binder Driver for common transactions.

  • Read_size =256, data needs to be read during this communication;

When can write_size be equal to 0 but read_size be different? The core method talkWithDriver() for user space to interact with the Binder Driver of kernel space is as follows:

Read_size = 0 doReceive=true, needRead=true, mIn = null; Add write_size=0 and mOut is null. This means that the Blocked thread’s mIn and mOut were empty the last time it interacted with the Binder driver.

The current thread is stuck in attachApplicationLocked(), which must write data to the mOut during execution. However, from the last scene after the incident, the data in mOut was empty, which was a violation of routine operation. The first instinct may suspect whether there was a memory stampede or something like that, but it is impossible to stampede only this data every time. For further verification, the data of mOut and mIn buffers were taken out.

3.5 mOut && mIn

The IPCThreadState structure sets the size of mOut and mIn to 256 when initialized. The Binder IPC process uses mOut and mIn to write data to and read data from Binder drivers, respectively.

Although old commands may be overwritten in the process of repeated use, there may be some useful information.

MOut and mIn are user-space data and are member variables of the IPCThreadState object. The program stops at waitForResponse() of IPCThreadState in user space and uses GDB to print out all members of this pointer in the current thread’s user space to find mOut and mIn

MDataSize = 16; mDataPos = 16; mDataSize = 16; MOut cache, mDataSize = 0, mDataPos = 0, indicating that BC_XXX has been consumed

From the figure above, it can be seen that the mData addresses of mIn and mOut are 0x7747500300 and 0x7747500400 respectively, and the size of the cache is 256 bytes. The mIn cache contains BR_XXX commands (0x72). The mOut cache contains BC_XXX commands (0x63). Let’s look at the data in the two caches separately:

MIn cache data:

BR_NOOP = 0x720C, BR_CLEAR_DEATH_NOTIFICATION_DONE = 0x7210, BR_CLEAR_DEATH_NOTIFICATION_DONE = 0x7210 BR_NOOP, BR_CLEAR_DEATH_NOTIFICATION_DONE

MOut cache data:

BC_FREE_BUFFER = 0x6303, BC_DEAD_BINDER_DONE = 0x6310, mOut data area last talkWithDriver process, consumed BC command sequence: BC_FREE_BUFFER, BC_DEAD_BINDER_DONE

The contents of mOut and mIn data areas in the two Ramdumps are basically the same, and BC and BR information in the cache are the same. The toDO queue of the blocked thread is empty. The last transaction processed was BC_FREE_BUFFER, BC_DEAD_BINDER_DONE, and BR_NOOP, BR_CLEAR_DEATH_NOTIFICATION_DONE, so there are only so many clues that can be read that are relevant to this case.

3.6 Difficult and pending cases

Solving a system problem can be as difficult as solving a crime, and this case is like a closet murder.

How did the murderer escape from the scene (todo queue is empty) when the door and window are locked internally (write_size of mIn buffer is equal to 0)? A sword wound from the victim’s body (blocked thread) is not fatal (asynchronous threads are not blocked), so what was the cause of death?

From the evidence of the crime scene (Ramdump inference), it is likely that this was not the first crime scene (the BUG was not found in the current Binder transaction), and it is most likely that the murderer committed the crime there (other transaction). Then move the body to the current crime scene (binder finishes nesting and returns to the previous level), then where is the real first crime scene?

After 18 rounds of Trace, Log, Ramdump derivation, Crash, GDB, and so on, there is no more information to dig into, and this problem is almost a headless mystery.

4. The truth is out

4.1 Case detection

The case is stuck all day, like a few lumps of fat. Repeated replay of the surrounding layout of the crime scene in my mind, a very important doubt came into my mind, among which one object (BC_DEAD_BINDER_DONE protocol) should normally be in the other room (binder death obituary related), But why is it at the scene of the crime (waitForResponse of bindApplication)?

Based on the final scene, follow this clue through reverse reasoning analysis, to try to deduce the murderer’s entire crime process. However, for such a complex case (binder communication systems have a large number of transactions occurring all the time, and the conversion between protocols is also complicated).

The reverse reasoning process is very complex, through continuous reverse combined with positive analysis, reverse back, each layer will have N possibility, as much as possible to rule out impossible branch, reserves the branch may continue to back again, in the inference process is most burning brain and time-consuming, see cover photo there is a lot of reasoning process. Finally miraculously found the first crime scene, also found a way to reproduce, in order to save space, here omitted ten thousand words.

The actual first scene is as follows: Kill the process shortly before executing the linkToDeath() method to reactivate the screen:

4.2 Interpretation of case files

The problem is complicated by the fact that even after finding the first crime scene and the recurrence path, it is difficult to fully understand every protocol switch in between. Run the following command to enable ftrace information about the Binder driver to output communication protocols and data.

BINDER_WORK_XXX (BW_XXX for short)

  • MOut: Records commands written to Binder drivers from user space

    • BC commands are consumed through the binder_thread_write() and binder_transaction() methods and the corresponding BW_XXX commands are generated, or BW commands may not be generated

    • When a thread – > return_error CMD! = BR_OK, the binder_thread_write() procedure will not be executed

  • Thread → toDO: Records BINDER_WORK waiting for the current binder thread

    • BW commands are consumed through the binder_thread_read() method and the corresponding BR_XX commands are produced, or BR commands may not be produced

    • In general, no BC_TRANSACION or BC_REPLY is read. BW_DEAD_BINDER exception;

  • MIn: Records the commands transmitted to the user space by the Binder Driver

    • BR commands are consumed through the waitForResponse() and executeCommand() methods

In addition, regarding talkWithDriver, when mIn has data, it means that data does not need to be read from the Binder driver first. Cause: needRead=0, read_buffer size is set to 0, and when doReceive=true, write_buffer size is also set to 0. Therefore, there is no interaction with the driver this time.

Details of the incident:

Process interpretation :(9 talkWithDriver times in the whole process)

  1. The thread executes linkToDeath() and writes BW_DEAD_BINDER to the Thread todo queue using flush.

  2. Execute bindApplication() and write BW_RETURN_ERROR to the toDO queue since the target process is dead, return_error.cmd = BR_DEAD_REPLY; Kernel space, convert BW_DEAD_BINDER to BR_DEAD_BINDER, synchronously place BW_DEAD_BINDER in proc->delivered_death; Back in user space, sendObituary() is still on waitForResponse() at bindApplication().

  3. CMD = BR_DEAD_REPLY add BC_CLEAR_DEATH_NOTIFICATION to mOut, flush with return_error. CMD = BR_DEAD_REPLY.

  4. CMD = BR_DEAD_REPLY, BW_RETURN_ERROR, and set return_error. CMD =BR_OK; Back in user space, terminates the first reportOneDeath(), mistakenly consuming the BR_DEAD_REPLY generated by bindApplication().

  5. Execute the second reportOneDeath(), consuming the BR_TRANSACTION_COMPLETE protocol generated by the first and second reportOneDeath, Since the second reportOneDeath is synchronous with binder Call, you still need to wait for the BR_REPLY protocol.

  6. Binder_wait_for_work () waits for the BC_REPLY command from the target process and puts BW_TRANSACTION into the toDO queue of the current thread. Upon receipt of the BW_TRANSACTION protocol, it is converted to BR_REPLY, completing the second reportOneDeath().

  7. Execute the third reportOneDeath() and complete the second reportOneDeath() upon receipt of BR_TRANSACTION_COMPLETE.

  8. When sendObituary() is complete, you need to add the BC_DEAD_BINDER_DONE protocol to mOut. After receiving this protocol, Proc →delivered_death set BW_DEAD_BINDER_AND_CLEAR to BW_CLEAR_DEATH_NOTIFICATION and place thread->todo in queue; Then generate BR_CLEAR_DEATH_NOTIFICATION_DONE to complete the communication.

  9. Back to the waitForResponse of bindApplication(), where both mOut and mIn are empty, and into the kernel binder_wait_for_work(), the thread receives no more transactions and cannot generate any, and is stuck forever.

Altogether, asynchronous binder calls block for the following reasons:

  • The first asynchronous reportOneDeath() consumes the BW_RETURN_ERROR generated by bindApplication();

  • The second synchronous reportOneDeath() consumes the residual BR_TRANSACTION_COMPLETE of the first asynchronous reportOneDeath() itself;

  • BW_RETURN_ERROR generated by bindApplication() is consumed by someone else, resulting in an endless wait.

4.3 summarize

The real analysis is far more complex than this, and given the length of the article, only one scenario is covered, with different Binder drivers and different combinations of Framework code representing and handling several different processes. The most fundamental problems are exceptions caused by BR_DEAD_REPLY errors consumed by other communications during nested binder communication.

My solution is to place the BW_RETURN_ERROR transaction in the head of the toDO queue of the current thread when a transaction error occurs, so that the BW_RETURN_ERROR transaction will be consumed correctly. So as to solve the problem of infinite blocking of asynchronous binder communication in nested scenarios, the optimized processing flow chart is as follows:

The second solution, of course, is to avoid all binder nesting whenever possible. Google’s latest Binder driver uses BW_DEAD_BINDER in the Proc toDO queue to avoid nesting, as well as the solution itself. However, I think BW_RETURN_ERROR should be placed at the head of the queue in the execution process to deal with error at the first time, so as to avoid the BUG of being consumed by errors. In addition, if binder adds other logic later, nesting may also occur, so there will still be similar problems.

I’ve talked to Google engineers about this a few times recently, but they still want to keep adding transactions to the end of the Thread Todo queue at a time, and they want to solve the nesting problem by putting it on the Proc Todo queue. In this regard, it is worried that the subsequent expansibility will be ignored or forgotten, which will cause the nesting problem with binder. Google engineers said that the new functions will be added in the future, and the nesting logic will be eliminated, so as to keep the logic and code simple.

Finally, after reportOneDeath consumes the BW_RETURN_ERROR generated by the bindApplication, Moving the body to the current crime scene (back to bindApplication’s waitForRespone method after executing BR_DEAD_BINDER) causes asynchronous Binder calls to block as well.

Android dharma school