Android Performance

Case Study: Debugging the Android Launcher Kill Problem

Word count: 811Reading time: 5 min
2019/09/17
loading

This article was inspired by a real-world bug I encountered. While the issue itself wasn’t particularly “hard,” the analysis process—the tools used, the investigative logic, and some clever tips I learned from a colleague—made it a perfect candidate for a case study.

I’ve used a variety of tools mentioned in my Android Performance Optimization Methodology, including:

  • Reproduction Video
  • Event Log
  • AS Source/Debug
  • AS Profiler
  • Systrace
  • Dumpsys
  • Unix ps utility

My goal is to document this process for myself and to share a universal troubleshooting workflow that might help others. If you have your own debugging tips, feel free to join our discussion group!

The Phenomenon

Testing reported a classic performance bug: “Slow loading of icons when returning to the home screen.” They provided a video, logs, and a Systrace.

The Analysis

1. Zeroing in on the Time

  1. Reproduction Video: I watched the video to find the exact minute the issue occurred.
  2. Event Log: I cross-referenced the video time with the Event Log to find the precise second.
  3. Operation Reconstruction: By reading the Event and Main logs, I reconstructed the user’s actions. Every time the app com.jx.cmcc.ict.ibelieve was launched, the Launcher was killed.
1
2
3
4
5
6
7
8
9
10
11
12
13
EventLog Snippet:
// App Launch: com.jx.cmcc.ict.ibelieve
09-10 10:14:48.877 ... I am_set_resumed_activity: [0,com.jx.cmcc.ict.ibelieve/.ui.MainTabActivity,...]

// LAUNCHER IS KILLED HERE
09-10 10:14:48.903 ... I am_kill : [0,13509,com.meizu.flyme.launcher,600,kill background]

// Returning to Launcher
09-10 10:14:51.990 ... I am_pause_activity: [0, ...MainTabActivity]

// Re-creating Launcher Process
09-10 10:14:52.025 ... I am_proc_start: [0,14013,10021,com.meizu.flyme.launcher,activity,...]
09-10 10:14:52.437 ... I am_activity_launch_time: [0, ...Launcher,413,413]

Initial Conclusion: The “slow loading” reported by testing is because the Launcher process was killed in the background. When the user returns to the home screen, the Launcher has to perform a cold start. While the log says 413ms for the Activity launch, the total time until icons appear is much longer (~2s) because it has to reload all content from the database.

2. Investigating the Kill Reason

The log says: am_kill : [..., kill background].
In the AOSP source code, kill background as a reason is issued specifically in AMS.killBackgroundProcesses.

1
2
3
4
5
6
7
// ActivityManagerService.java
public void killBackgroundProcesses(final String packageName, int userId) {
synchronized (this) {
killPackageProcessesLocked(packageName, appId, targetUserId,
ProcessList.SERVICE_ADJ, false, true, true, false, "kill background");
}
}

This method is exposed to third-party apps via ActivityManager.killBackgroundProcesses(packageName).

3. Debugging SystemServer

We need to catch which app is calling this method. I set a breakpoint in ActivityManagerService.killBackgroundProcesses inside the system_process process.

  1. Attach the debugger to system_process.
  2. Launch the suspicious app.
  3. The breakpoint hits! I use the expression evaluator to find the caller PID: getRealCallingPid().
    • Result: 29771.
  4. Checking ps -A | grep 29771: It’s com.jx.cmcc.ict.ibelieve.

4. Debugging the App

To confirm, I attached a debugger to the app process itself. Since I don’t have its source, I placed a breakpoint in the public SDK method android.app.ActivityManager.killBackgroundProcesses.

Every time I log into the app and go back to the home screen, the breakpoint hits. The app is actively killing the background environment.

5. Identifying the Root Code using AS Profiler

Using the Android Studio Profiler (CPU -> Trace Java Methods), I recorded a trace while the app was running. After stopping the record, I searched the call stack for killBackgroundProcesses.

The trace showed that inside its loadComplete callback, the app explicitly calls its own killBackground utility method. (This is where the app developer would go to fix the bug).

6. Permission Analysis

killBackgroundProcesses requires the Manifest.permission.KILL_BACKGROUND_PROCESSES permission.
Checking dumpsys package com.jx.cmcc.ict.ibelieve:

1
2
install permissions:
android.permission.KILL_BACKGROUND_PROCESSES: granted=true

This is a “normal” level permission. This means any app can request it in the manifest and the system will grant it automatically without a user prompt. In this case, a developer used it—either accidentally or over-zealously—to “clean up” memory, but accidentally nuked the launcher in the process.

7. Can Systrace find the Culprit?

Yes. If you trace the killProcessGroup event in the system_server process, you can look for the “Waking From” thread.

  1. Find killProcessGroup in system_server.
  2. Follow the wakeup chain back.
  3. It leads back to a Binder thread in system_server, which was triggered by the main thread of PID 7289 (com.jx.cmcc.ict.ibelieve).

Conclusion

This issue was caused by an app requesting a powerful permission and using it incorrectly. It shows that even a “simple” app can severely degrade the OS experience if it plays loose with system-level APIs.

Interestingly, Google allows the KILL_BACKGROUND_PROCESSES permission at the “normal” level. Given it affects the lifecycle of other apps, one might argue it should be a more restricted permission.


About Me && Blog

(Links and introduction)

CATALOG
  1. 1. The Phenomenon
  2. 2. The Analysis
    1. 2.1. 1. Zeroing in on the Time
    2. 2.2. 2. Investigating the Kill Reason
    3. 2.3. 3. Debugging SystemServer
    4. 2.4. 4. Debugging the App
    5. 2.5. 5. Identifying the Root Code using AS Profiler
    6. 2.6. 6. Permission Analysis
    7. 2.7. 7. Can Systrace find the Culprit?
  3. 3. Conclusion
  4. 4. About Me && Blog