Android 框架問題分析案例 - 誰殺了桌面?

作者：高爺 2019-09-18 09:06:20

寫這篇文章的契機是因為一個實際遇到的問題 , 這個問題其實不難 , 不過在分析了這個問題然后寫日記的時候 , 我突然覺得這個問題分析的過程有必要記錄一下 , 分享給大家。

寫這篇文章的契機是因為一個實際遇到的問題 , 這個問題其實不難 , 不過在分析了這個問題然后寫日記的時候 , 我突然覺得這個問題分析的過程有必要記錄一下 , 分享給大家。分析過程中有用到一些工具 , 一些方法 , 也從另外一個聰明的小伙伴梅明那里學到了一些分析技巧和工具的使用技巧。

這篇文章中分析過程包括我之前在 Android 中的卡頓丟幀原因概述 - 方法論里面提到的一些工具 , 包括 : 復現視頻 \ Event Log \ Android Studio 源碼和 App Debug \ Android Studio Profile \ Systrace \ Dumpsys \ PS 等 . 大多數工具大家都在開發過程中使用過 , 這次分析正是使用了這些工具相互配合 , 最終找到的問題的原因。

大家看下來可能會覺得 , 這么簡單一個問題還需要寫一篇文章 ? 我寫這篇文章的目的一是為了記錄給自己 , 二是覺得分析過程比較有普遍性 , 包括分析思路和工具的使用 , 如果可以幫助到大家 , 那么最好不過了 , 如果你也有好的思路或者獨家調試技巧 , 歡迎大家掃描關于我里面的討論群二維碼加入群聊 , 共同進步!

現象

這個問題是測試直接報過來的 , Bug 描述是典型的按現象描述 : “ 從應用返回桌面 , 桌面圖標加載慢 “. 測試這邊提供了錄制的視頻和抓取的 Log , 以及對應的 Systrace 等. 既然現象和 Log 都在 , 那么就開始分析吧.

分析過程

確定問題發生的時間點

由于測試提供的復現視頻 , 首先看復現視頻 , 確定時間發生的時間
根據視頻里面的大概時間(精確到分) , 查看對應的 EventLog ，跟視頻比對，確定發生的確切時間點 (精確到秒)
查看 EventLog 和 MainLog ，還原發生時候的用戶操作，這個例子里面就發現啟動和我信這個 App 之后，Launcher 被殺了

EventLog 
// 啟動 com.jx.cmcc.ict.ibelieve 這個 App 
09-10 10:14:48.877  1456  2269 I am_set_resumed_activity: [0,com.jx.cmcc.ict.ibelieve/.ui.MainTabActivity,resumeTopActivityInnerLocked] 
09-10 10:14:48.886  1456  2269 I am_resume_activity: [0,80317506,54938,com.jx.cmcc.ict.ibelieve/.ui.MainTabActivity] 
09-10 10:14:48.891  1456  1485 I sysui_count: [window_time_0,0] 
09-10 10:14:48.891  1456  1485 I sysui_multi_action: [757,803,799,window_time_0,802,0] 
09-10 10:14:48.902  1456  2269 I am_uid_stopped: 10021 
 
// 這里桌面被殺 
09-10 10:14:48.903  1456  2269 I am_kill : [0,13509,com.meizu.flyme.launcher,600,kill background] 
 
// 這里開始從 App 返回桌面 
09-10 10:14:51.990  1456  1791 I am_pause_activity: [0,80317506,com.jx.cmcc.ict.ibelieve/.ui.MainTabActivity] 
09-10 10:14:51.994  1456  1791 I am_task_to_front: [0,54923] 
09-10 10:14:51.996 13674 13674 I am_on_paused_called: [0,com.jx.cmcc.ict.ibelieve.ui.MainTabActivity,handlePauseActivity] 
09-10 10:14:52.013  1456  2270 I am_uid_running: 10021 
 
// 重新創建桌面進程 
09-10 10:14:52.025  1456  2270 I am_proc_start: [0,14013,10021,com.meizu.flyme.launcher,activity,com.meizu.flyme.launcher/.Launcher] 
09-10 10:14:52.045  1456  2270 I am_proc_bound: [0,14013,com.meizu.flyme.launcher] 
09-10 10:14:52.069  1456  2270 I am_uid_active: 10021 
09-10 10:14:52.069  1456  2270 I am_restart_activity: [0,238217861,54923,com.meizu.flyme.launcher/.Launcher] 
 
// 桌面顯示 
09-10 10:14:52.071  1456  2270 I am_set_resumed_activity: [0,com.meizu.flyme.launcher/.Launcher,minimalResumeActivityLocked] 
09-10 10:14:52.335 14013 14013 I am_on_resume_called: [0,com.meizu.flyme.launcher.Launcher,LAUNCH_ACTIVITY] 
09-10 10:14:52.437  1456  1504 I am_activity_launch_time: [0,238217861,com.meizu.flyme.launcher/.Launcher,413,413]

那么這里就可以簡單還原問題了 , 測試報的是 從應用返回桌面 , 桌面圖標加載慢 , 從 Event Log 來看 , 桌面顯示慢 , 是因為 桌面被殺了 , 所以從 App 返回的時候 , 桌面需要重新加載 , 從桌面進程創建到桌面完全顯示 , 花費了 413ms(實際到桌面完全顯示,花費了至少 2s 左右,因為 Launcher 冷啟動還要重新加載內容).

分析被殺原因

從上面的分析來看 , 我們需要找到 Launcher 被殺的原因 , 從現象上來看 , 似乎是和 com.jx.cmcc.ict.ibelieve 這個進程有關系 , 但是我們目前是沒有辦法確認的 .

這里我們重點看這個這個 Event Log

am_kill : [0,13509,com.meizu.flyme.launcher,600,kill background]

這里可以看到 Launcher 被殺的原因是 kill background , 查看對應的源碼可知，reason = kill background 是 AMS.killBackgroundProcesses 這里發出的.

ActivityManagerService.killBackgroundProcesses

public void killBackgroundProcesses(final String packageName, int userId) { 
...... 
            synchronized (this) { 
                killPackageProcessesLocked(packageName, appId, targetUserId, 
                        ProcessList.SERVICE_ADJ, false, true, true, false, "kill background"); 
            } 
}

對源碼比較熟悉的同學可以很快知道 , AMS.killBackgroundProcesses 這個接口會提供給三方應用去調用 , 其 Binder 的客戶端在 ActivityManager.killBackgroundProcesses 這里

ActivityManager.killBackgroundProcesses

/** 
 * Have the system immediately kill all background processes associated 
 * with the given package.  This is the same as the kernel killing those 
 * processes to reclaim memory; the system will take care of restarting 
 * these processes in the future as needed. 
 * 
 * @param packageName The name of the package whose processes are to 
 * be killed. 
 */ 
@RequiresPermission(Manifest.permission.KILL_BACKGROUND_PROCESSES) 
public void killBackgroundProcesses(String packageName) { 
    try { 
        getService().killBackgroundProcesses(packageName, 
                mContext.getUserId()); 
    } catch (RemoteException e) { 
        throw e.rethrowFromSystemServer(); 
    } 
}

對 SystemServer 進程進行斷點 Debug

知道了上面的代碼邏輯 , 我們需要做的就是找到在這個場景下 , 是哪個應用調用 ActivityManager.killBackgroundProcesses 殺掉了桌面. 由于不知道具體是哪個應用(這里雖然我們懷疑是 com.jx.cmcc.ict.ibelieve , 但是沒有證據) , 我們先對 SystemServer 進程進行 Debug .

1.首先對源碼進行 debug , 首先在 Android 中點擊 debug 按鈕 , 選擇 system_process 這個進程(就是我們所說的 SystemServer) , 然后點擊 OK . 代碼的斷點我們打在上面列出的 ActivityManagerService.killBackgroundProcesses 方法里面。

2.點擊啟動懷疑的 App ( 可以從 EventLog 和視頻里面倒推，找到比較可疑的 App , 安裝后進行本地測試復現 , 這里選擇了視頻中出現的幾個應用,包括我們之前懷疑的 com.jx.cmcc.ict.ibelieve- 和我信 ) , 點擊其他的應用都不會進入到這個斷點, 而在點擊 和我信 這個 App 啟動后走到的斷點。

3.這里我們可以看到調用棧是一個 Binder 調用 , 我們需要找到這個 Binder 調用的客戶端. 在 AS 里面繼續操作 , 點擊如下圖的計算器按鈕 , 輸入 getRealCallingPid() 點擊下面的 Evaluate , 就可以看到結果. result = 29771

4.通過 PS 命令 , 查看這個 pid 對應的 app。

可以看到就是這個應用調用的 killBackgroundProcesses。

對 App 進程進行斷點 Debug

為了進一步調查，我們對這個 app 進行 debug ，由于沒有源碼，我們直接把斷點打到 android/app/ActivityManager.killBackgroundProcesses 這里(因為這里是客戶端代碼 , 所以調試 App 進程的時候 , 可以直接打斷點 )。

本地安裝這個應用進行調試，發現登錄后，再次啟動，桌面必會被殺，確定就是這個 App 的問題。

到了這一步我們已經基本上確定問題就是這個 App 引起的了 , 不過如果我們想看比較詳細的調用情況 , 可以使用 Android Studio Profile。

使用 Android Studio Profiler 工具

打開 Android Studio , 點擊 Profiler 按鈕 , 點擊 + 號 , 選擇 com.jx.cmcc.ict.ibelieve 這個進程 , 然后點擊 CPU 這一欄。

這里選擇了 Trace Java Methods , 然后點擊旁邊的 Record , 就可以開始進行操作 , 操作結束后 , 點擊 Stop , AS 會自動開始解析。

解析結果我們可以看這里：

最下面就是剛剛操作所對應的詳細函數調用棧 , 以真正運行的順序展示在我們面前(我經常會用這個工具來查看源碼邏輯和三方應用的代碼邏輯 , 不管是學習還是解決問題 , 都是一個非常好的方法)。

我們使用 ctrl+f 進行搜索 killBackgroundProcesses , 如果有的話 , 會以高亮顯示, 我們只需要用鼠標放大就可以看到詳細的調用棧。

可以看到這個 App 在 loadComplete 回調里面執行了 killBackground 方法.(到了這里，應用開發者就已經知道是哪里的問題了，修復起來飛快)。

權限問題分析

如上面所示 , 調用 killBackgroundProcesses 是需要Manifest.permission.KILL_BACKGROUND_PROCESSES 這個權限的。

@RequiresPermission(Manifest.permission.KILL_BACKGROUND_PROCESSES) 
public void killBackgroundProcesses(String packageName) { 
}

執行 adb shell dumpsys package com.jx.cmcc.ict.ibelieve 查看 com.jx.cmcc.ict.ibelieve 這個進程所申請的權限 , 發現這個應用在安裝的時候就申請了KILL_BACKGROUND_PROCESSES 這個權限 , 且默認是授予的。

install permissions: 
  ...... 
  android.permission.ACCESS_NETWORK_STATE: granted=true 
  android.permission.KILL_BACKGROUND_PROCESSES: granted=true 
  android.permission.WRITE_USER_DICTIONARY: granted=true 
  ......