Android Systrace Basics - Binder and Lock Contention Explained

Word count: 1.9kReading time: 12 min

 2019/12/06

This is the tenth article in the Systrace series, primarily providing a brief introduction to Binder and lock information in Systrace. It covers the basic situation of Binder, the representation of Binder communication in Systrace, how to view Binder information, and analysis of lock contention in SystemServer.

The purpose of this series is to view the overall operation of the Android system from a different perspective using Systrace, while also providing an alternative angle for learning the Framework. Perhaps you’ve read many articles about the Framework but can never remember the code, or you’re unclear about the execution flow. Maybe from Systrace’s graphical perspective, you can gain a deeper understanding.

Series Article Index
Binder Overview
Binder Call Diagram
Lock Information in Systrace
Waiting for Lock Analysis
Related Code
References
Attachments
About Me && Blog

Series Article Index

Binder Overview

Most inter-process communication in Android uses Binder. I won’t provide an over-explanation of Binder here. If you want a deep understanding of Binder’s implementation, I recommend reading these three articles:

The reason for discussing Binder and locks in Systrace separately is that many jank and responsiveness issues stem from cross-process Binder communication. Lock contention can extend Binder communication time, affecting the calling end. A classic example is when an app’s rendering thread calls dequeueBuffer, and the SurfaceFlinger main thread is blocked, causing the dequeueBuffer to take longer and resulting in app jank. Another example is when AMS or WMS methods in SystemServer are holding locks, causing long wait times for app calls.

Here is a Binder architecture diagram from an article. This piece focuses on Systrace, so we’ll cover how Binder appears in Systrace without diving into its internal implementation.

Binder Call Diagram

Binder is primarily used for cross-process communication. The diagram below simply shows how Binder communication is displayed in Systrace:

In the diagram, the SystemServer process is communicating with Qualcomm’s perf process. Enabling Flow Events in the ViewOptions in the top right corner of Systrace will reveal Binder information.

Clicking on a Binder event reveals detailed information. Some of this data is useful during problem analysis, but we won’t go into detail here.

For Binder, this section focuses on how to view lock information and lock waiting in Systrace. Analyzing many jank and responsiveness issues depends on interpreting this information. Ultimately, you’ll need to return to the code: once an issue is identified, read the source code to understand the logic and perform appropriate optimizations.

Lock Information in Systrace

monitor contention with owner Binder:1605_B (4667) at void com.android.server.wm.ActivityTaskManagerService.activityPaused(android.os.IBinder)(ActivityTaskManagerService.java:1733) waiters=2 blocking from android.app.ActivityManager$StackInfo com.android.server.wm.ActivityTaskManagerService.getFocusedStackInfo()(ActivityTaskManagerService.java:2064)

Let’s break the above message into two parts, using blocking as the dividing line.

Part 1 Interpretation

monitor contention with owner Binder:1605_B (4667) at void com.android.server.wm.ActivityTaskManagerService.activityPaused(android.os.IBinder)(ActivityTaskManagerService.java:1733) waiters=2

Monitor refers to the current pool for the lock object. In Java, every object has two pools: a lock (monitor) pool and a wait pool.

Lock Pool (Synchronized Queue): Suppose thread A already owns the lock of an object (not a class). Other threads wanting to call a synchronized method (or block) on this object must first acquire ownership of that object’s lock. Since thread A currently owns it, these other threads enter the object’s lock pool.

The word contention is used here, meaning there’s a struggle because the object’s lock is currently held by another object (Owner), so ownership cannot be acquired, and the thread enters the lock pool.

Owner: The object currently possessing the lock for this object. Here, it’s Binder:1605_B, with thread ID 4667.

at: Describes what the Owner thread is currently doing. Here, it’s executing the void com.android.server.wm.ActivityTaskManagerService.activityPaused method. The code location is ActivityTaskManagerService.java:1733. The corresponding code is:

com/android/server/wm/ActivityTaskManagerService.java

@Override
public final void activityPaused(IBinder token) {
    final long origId = Binder.clearCallingIdentity();
    synchronized (mGlobalLock) { // Line 1733 is here
        ActivityStack stack = ActivityRecord.getStackLocked(token);
        if (stack != null) {
            stack.activityPausedLocked(token, false);
        }
    }
    Binder.restoreCallingIdentity(origId);
}

We can see synchronized (mGlobalLock) acquires the ownership of the mGlobalLock lock. Until it releases the lock, any other place calling synchronized (mGlobalLock) must wait in the lock pool.

waiters: The number of operations currently waiting in the lock pool for the object’s lock. waiters=2 indicates there’s already one operation waiting for the lock, so adding this one makes a total of three.

Part 2 Interpretation

blocking from android.app.ActivityManager$StackInfo com.android.server.wm.ActivityTaskManagerService.getFocusedStackInfo()(ActivityTaskManagerService.java:2064)

The second part is simpler: it identifies the method currently being blocked while waiting for the lock. Here, ActivityManager‘s getFocusedStackInfo is blocked. The corresponding code is:

com/android/server/wm/ActivityTaskManagerService.java

@Override
public ActivityManager.StackInfo getFocusedStackInfo() throws RemoteException {
    enforceCallerIsRecentsOrHasPermission(MANAGE_ACTIVITY_STACKS, "getStackInfo()");
    long ident = Binder.clearCallingIdentity();
    try {
        synchronized (mGlobalLock) { // Line 2064 is here 
            ActivityStack focusedStack = getTopDisplayFocusedStack();
            if (focusedStack != null) {
                return mRootActivityContainer.getStackInfo(focusedStack.mStackId);
            }
            return null;
        }
    } finally {
        Binder.restoreCallingIdentity(ident);
    }
}

This also calls synchronized (mGlobalLock) (Note: The original text might have varied between mGlobalLock and ActivityManagerService.this due to Android versions, but the principle is the same), requiring wait for the ownership of the object’s lock.

Summary

The above message translates to:

The getFocusedStackInfo method of ActivityTaskManagerService was blocked during execution because it couldn’t acquire ownership of the synchronization object’s lock when executing a synchronized block. It must wait until another method, ActivityTaskManagerService.activityPaused, which currently owns the lock, finishes execution before it can acquire ownership and continue.

Compare with the original text:

monitor contention with owner Binder:1605_B (4667)
at void com.android.server.wm.ActivityTaskManagerService.activityPaused(android.os.IBinder)(ActivityTaskManagerService.java:1733)
waiters=2
blocking from android.app.ActivityManager$StackInfo com.android.server.wm.ActivityTaskManagerService.getFocusedStackInfo()(ActivityTaskManagerService.java:2064)

Waiting for Lock Analysis

In the same Systrace, the Binder info shows waiters=2, meaning two operations preceded this one in waiting for the lock release. This sums to three operations waiting for Binder:1605_B (4667) to release the lock. Let’s look at the execution of Binder:1605_B:

The diagram shows Binder:1605_B executing activityPaused, with some other Binder operations in between, before finally releasing the lock upon completion.

Now let’s trace the execution order, including the two waiters:

Lock Waiting

The diagram illustrates the contention for the mGlobalLock object lock:

Binder_1605_B first begins executing activityPaused, which requires the mGlobalLock lock. Since there’s no current contention, activityPaused acquires the lock and starts.
The android.display thread starts executing the checkVisibility method, which also needs the mGlobalLock lock. Since Binder_1605_B holds it, checkVisibility waits and enters a sleep state.
The android.anim thread starts executing relayoutWindow, also needing the mGlobalLock lock. Since Binder_1605_B holds it, it also waits and enters sleep.
The android.bg thread starts getFocusedStackInfo, also needing the lock. It also waits and sleeps.

After these four steps, Binder_1605_B is running while the other three threads failed to acquire the mGlobalLock lock and are sleeping, waiting for Binder_1605_B to finish and release the lock.

Lock Release

This diagram shows the lock release and subsequent flow:

Binder_1605_B‘s activityPaused finishes, and the mGlobalLock lock is released.
The first waiting thread, android.display, starts executing checkVisibility. Its wakeup info shows it was woken by Binder_1605_B (4667).
checkVisibility finishes, and the lock is released.
The second waiting thread, android.anim, starts relayoutWindow. Its wakeup info shows it was woken by android.display (1683).
relayoutWindow finishes, and the lock is released.
The third waiting thread, android.bg, starts getFocusedStackInfo. It was woken by android.anim (1684).

After these 6 steps, this round of lock waiting caused by mGlobalLock concludes. This is a simple example; in practice, Binder lock waiting in SystemServer can be very severe, with waiters often reaching 7-10—quite alarming, as seen below:

This explains why the system can become laggy after many apps are installed or after prolonged use. A brief period of this can also occur after a reboot.

If you’re unsure how to view wakeup information, refer to this article: Analyzing Process Wakeup Information in Systrace.

Monitor Info

art/runtime/monitor.cc

std::string Monitor::PrettyContentionInfo(const std::string& owner_name,
                                          pid_t owner_tid,
                                          ArtMethod* owners_method,
                                          uint32_t owners_dex_pc,
                                          size_t num_waiters) {
  Locks::mutator_lock_->AssertSharedHeld(Thread::Current());
  const char* owners_filename;
  int32_t owners_line_number = 0;
  if (owners_method != nullptr) {
    TranslateLocation(owners_method, owners_dex_pc, &owners_filename, &owners_line_number);
  }
  std::ostringstream oss;
  oss << "monitor contention with owner " << owner_name << " (" << owner_tid << ")";
  if (owners_method != nullptr) {
    oss << " at " << owners_method->PrettyMethod();
    oss << "(" << owners_filename << ":" << owners_line_number << ")";
  }
  oss << " waiters=" << num_waiters;
  return oss.str();
}

Block Info

art/runtime/monitor.cc

if (ATRACE_ENABLED()) {
  if (owner_ != nullptr) {  // Did the owner_ give the lock up?
    std::ostringstream oss;
    std::string name;
    owner_->GetThreadName(name);
    oss << PrettyContentionInfo(name,
                                owner_->GetTid(),
                                owners_method,
                                owners_dex_pc,
                                num_waiters);
    // Add info for contending thread.
    uint32_t pc;
    ArtMethod* m = self->GetCurrentMethod(&pc);
    const char* filename;
    int32_t line_number;
    TranslateLocation(m, pc, &filename, &line_number);
    oss << " blocking from "
        << ArtMethod::PrettyMethod(m) << "(" << (filename != nullptr ? filename : "null")
        << ":" << line_number << ")";
    ATRACE_BEGIN(oss.str().c_str());
    started_trace = true;
  }
}

References

Attachments

The attachments involved in this article have been uploaded. Download, extract, and open them in Chrome:
Click here to download the Systrace attachments related to the article

About Me && Blog

Below is my personal intro and related links. I look forward to exchanging ideas with fellow professionals. “When three walk together, one can always be my teacher!”