天天看點

Android App 啟動過程分析

原文連結:http://harttle.com/2014/05/27/android-appstartup.html

通過分析和修改Android 源碼,分析 Android App 啟動過程的時間消耗及性能瓶頸。

本文包括源碼編譯與運作、源碼修改與調試、資料收集與分析。分析了 App 啟動過程中,

Activity Manager Service

Binder

Launcher

MainActivity

扮演的角色以及消耗的時間。

源碼編譯與運作

環境配置

環境要求可以在從 文檔 查詢得到。以下在Arch Linux中進行Android Source Building的環境配置。

安裝依賴

# x86
yaourt -S --needed gcc git gnupg flex bison gperf sdl wxgtk squashfs-tools curl ncurses zlib schedtool perl-switch zip unzip libxslt

# x64
yaourt -S --needed gcc-multilib lib32-zlib lib32-ncurses lib32-readline

# Android 工具
yaourt -S android-sdk android-sdk-platform-tools android-sdk-build-tools android-studio
           

增加交換空間,加 RAM 應達到 16G (另外,還需要 30G 的大小寫敏感檔案系統可用空間)

su
swapoff /swapfile && rm /swapfile
dd if=/dev/zero of=/swapfile bs=M count=
mkswap /swapfile && swapon /swapfile
           

環境降級

# make 3.81-3.82
yaourt -S make- 

# python2
cd /usr/bin && sudo ln -sf python python2

# java SE 1.6
yaourt -S jdk6-compat
           

環境配置

#!/bin/bash
# file: env.sh

# cache
export USE_CCACHE=
export CCACHE_DIR=~/.ccache

# output
export OUT_DIR_COMMON_BASE=~/code/androidcore/output

# alias
alias make='make-3.81'

# java6
export JAVA_HOME=/opt/java6
export PATH=/opt/java6/bin:$PATH
           

配置USB通路權限:

# file: /etc/udev/rules.d/51-android.rules

# adb protocol on passion (Nexus One)
SUBSYSTEM=="usb", ATTR{idVendor}=="18d1", ATTR{idProduct}=="4e12", MODE="0600", OWNER="<username>"
# fastboot protocol on passion (Nexus One)
SUBSYSTEM=="usb", ATTR{idVendor}=="0bb4", ATTR{idProduct}=="0fff", MODE="0600", OWNER="<username>"
# ...
           

最終環境

Linux acer --ARCH #1 SMP PREEMPT Mon Mar 24 20:06:08 CET 2014 x86_64 GNU/Linux
Python  (default, Feb  , ::)
gcc 版本   (prerelease) (GCC)
GNU Make 
java SE 
           

編譯Android Source

參照 文檔 ,下載下傳Android4.2源碼。

# 導入環境
. ../env.sh
. build/envsetup.sh

# 設定緩存大小
prebuilts/misc/linux-x86/ccache/ccache -M G

# 選擇目标
lunch

# 并行編譯
make -j4
           

啟動Emulator

# 加載環境
lunch 

# 啟動
emulator
           

啟動成功,Android版本為4.2.1:

Android App 啟動過程分析

源碼修改與調試

考慮從Launcher啟動應用程式時,

ActivityManagerService

Launcher

MainActivity

之間的執行與通信序列如下圖。在源碼中相應的過程調用或程序通信處加入日志資訊,用于分析啟動時各部分的耗時。

Android App 啟動過程分析

Android源碼修改

以下列出所有需要更改的源碼。注釋中給出了檔案路徑、類名、函數名,與添加的語句。添加日志輸出(Level為Info,Tag為”PKU”)。

說明:檔案

ApplicationThreadNative

沒有引入

Log

類。添加

import andriod.util.Log

會發生運作時錯誤,可能是因為該檔案的在類層次中的特殊性。是以我們将在

try catch

語句中指明命名空間并進行調用。我們關心的是整個系統啟動後的 App啟動過程,是以直接吞掉這個在早期才會産生的異常。

/
// file: packages/apps/Launcher2/src/com/android/launcher2/Launcher.java

// 0 Launcher.onClick
Log.i("PKU", "0 shortcut clicked");


/
// file: frameworks/base/core/java/android/app/ActivityManagerNative.java

// 1 ActivityManagerProxy.startActivity 
Log.i("PKU","1 START_ACTIVITY_TRANSACTION begin");
Log.i("PKU","1 START_ACTIVITY_TRANSACTION end");

// 5 ActivityManagerProxy.activityPaused
Log.i("PKU","5 ACTIVITY_PAUSED_TRANSACTION begin");
Log.i("PKU","5 ACTIVITY_PAUSED_TRANSACTION end");

// 9 ActivityManagerProxy.attachApplication
Log.i("PKU","9 ATTACH_APPLICATION_TRANSACTION begin");
Log.i("PKU","9 ATTACH_APPLICATION_TRANSACTION end");


/
// file: frameworks/base/services/java/com/android/server/am/ActivityManagerService.java

// 2 ActivityManagerService.startActivity
Log.i("PKU","2 on START_ACTIVITY_TRANSACTION");

// 6 ActivityManagerService.activityPaused
Log.i("PKU","6 on ACTIVITY_PAUSED_TRANSACTION");

// 7 ActivityManagerService.startProcessLocked
Log.i("PKU","7 process starting");
Log.i("PKU","7 process started");

// 10 ActivityManagerService.attachApplication
Log.i("PKU","10 on ATTACH_APPLICATION_TRANSACTION");


/
// file: frameworks/base/core/java/android/app/ApplicationThreadNative.java

// 3 ApplicationThreadProxy.schedulePauseActivity
try{
    android.util.Log.i("PKU","3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin");
}catch(Exception e){}
try{
    android.util.Log.i("PKU","3 SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end");
}catch(Exception e){}

// 11 ApplicationThreadProxy.scheduleLaunchActivity
try{
    android.util.Log.i("PKU","11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin");
}catch(Exception e){}
try{
    android.util.Log.i("PKU","11 SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end");
}catch(Exception e){}


/
// file: frameworks/base/core/java/android/app/ActivityThread.java

// 4 ApplicationThread.schedulePauseActivity 
Log.i("PKU","4 on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION");

// 8 ActivityThread.main
Log.i("PKU","8 main entered");

// 12 ApplicationThread.scheduleLaunchActivity
Log.i("PKU","12 on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION");
           

App源碼修改

/
// file: src/com/example/android/searchabledict/SearchableDictionary.java

import android.util.Log;

// SearchableDictionary.onCreate
Log.i("PKU", "searchabledictionary oncreate");

// SearchableDictionary.handleIntent
Log.i("PKU", "item clicked");


/
// file: src/com/example/android/searchabledict/SearchableDictionary.java

import android.util.Log;

// WordActivity.onCreate
Log.i("PKU", "wordactivity oncreate");
           

重新編譯

重新編譯Android Source

. ../env.sh
. build/envsetup.sh
prebuilts/misc/linux-x86/ccache/ccache -M G
lunch
make -j4
           

運作模拟器

emulator&
           

安裝測試應用:SearchableDictionary

# 拷貝Sample
cp -r /opt/android-sdk/samples/android-/legacy/SearchableDictionary/ .

# 建立Project
android update project -t  -n searchabledict -p ./SearchableDictionary

# 編譯
cd SearchableDictionary && ant debug

# 檢視正在運作的裝置
adb devices

# 安裝到指定裝置
adb -s emulator- install bin/searchabledict-debug.apk
           

安裝後在應用程式清單中出現SearchableDictionary:

Android App 啟動過程分析

資料采集與分析

資料采集

首先運作模拟器,在設定中更改 “background process limit” 為0,勾選”don’t keep activities”。這樣每次點選Home即可結束應用程序。

然後監視日志并重定向到檔案:

# 清空日志
adb -s emulator- logcat -c

# 開始過濾
adb -s emulator- logcat -v time PKU:I *:S | tee pku.log
           

現在,我們來獲得10組啟動過程的日志資料:

  1. 啟動SearchableDictionary;
  2. 點選搜尋,随機搜尋一個單詞并打開;
  3. 點選Home按鍵(因為我們隻關心啟動過程);
  4. 重複1-3;
  5. 結束

    logcat

    ,得到

    pku.log

    ,檔案46行為一個周期,10次測試共460行,前46行如下:
- :: I/PKU     (  ):  shortcut clicked
       - :: I/PKU     (  ):  START_ACTIVITY_TRANSACTION begin
       - :: I/PKU     (  ):  on START_ACTIVITY_TRANSACTION
       - :: I/PKU     (  ):  SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin
       - :: I/PKU     (  ):  on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION
       - :: I/PKU     (  ):  SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end
       - :: I/PKU     (  ):  START_ACTIVITY_TRANSACTION end
       - :: I/PKU     (  ):  ACTIVITY_PAUSED_TRANSACTION begin
       - :: I/PKU     (  ):  on ACTIVITY_PAUSED_TRANSACTION
      - :: I/PKU     (  ):  process starting
      - :: I/PKU     (  ):  process started
      - :: I/PKU     (  ):  ACTIVITY_PAUSED_TRANSACTION end
      - :: I/PKU     ( ):  main entered
      - :: I/PKU     ( ):  ATTACH_APPLICATION_TRANSACTION begin
      - :: I/PKU     (  ):  on ATTACH_APPLICATION_TRANSACTION
      - :: I/PKU     (  ):  SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin
      - :: I/PKU     (  ):  SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end
      - :: I/PKU     ( ):  on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION
      - :: I/PKU     ( ):  ATTACH_APPLICATION_TRANSACTION end
      - :: I/PKU     ( ): searchabledictionary oncreate
      - :: I/PKU     ( ):  START_ACTIVITY_TRANSACTION begin
      - :: I/PKU     (  ):  on START_ACTIVITY_TRANSACTION
      - :: I/PKU     ( ):  START_ACTIVITY_TRANSACTION end
      - :: I/PKU     ( ): item clicked
      - :: I/PKU     ( ):  START_ACTIVITY_TRANSACTION begin
      - :: I/PKU     (  ):  on START_ACTIVITY_TRANSACTION

      - :: I/PKU     (  ):  SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin
      - :: I/PKU     ( ):  on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION
      - :: I/PKU     (  ):  SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end
      - :: I/PKU     ( ):  START_ACTIVITY_TRANSACTION end
      - :: I/PKU     ( ):  ACTIVITY_PAUSED_TRANSACTION begin
      - :: I/PKU     (  ):  on ACTIVITY_PAUSED_TRANSACTION
      - :: I/PKU     (  ):  SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin
      - :: I/PKU     ( ):  on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION
      - :: I/PKU     (  ):  SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end
      - :: I/PKU     ( ):  ACTIVITY_PAUSED_TRANSACTION end
      - :: I/PKU     ( ): wordactivity oncreate
      - :: I/PKU     (  ):  SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin
      - :: I/PKU     ( ):  on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION
      - :: I/PKU     ( ):  ACTIVITY_PAUSED_TRANSACTION begin
      - :: I/PKU     (  ):  on ACTIVITY_PAUSED_TRANSACTION
      - :: I/PKU     (  ):  SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end
      - :: I/PKU     (  ):  SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin
      - :: I/PKU     (  ):  on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION
      - :: I/PKU     (  ):  SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end
      - :: I/PKU     ( ):  ACTIVITY_PAUSED_TRANSACTION end
           
  • 1-20行:點選Launcher圖示(Launcher.onClick)到Activity啟動完畢(SearchableDictionary.onCreate);
  • 21-23行:點選搜尋提示清單中的某一項到生成隐式Intent;
  • 24-37行:調用StartActivity(SearchableDictionary.handleIntent)到WordActivity啟動完畢(WordActivity.onCreate);
  • 38-46行:點選Home鍵直到應用程式程序結束(這一段不在我們關心的範圍内)。
可以看到到

begin

end

之間總會有

on

,即

transaction

類似遠端過程調用,該過程是同步的。

資料分析

利用腳本

pku_analyzer.sh

,計算日志檔案

pku.log

相鄰事件之間的時間差,最終結果(即 10 次測試的平均值)記錄在

r.txt

檔案:

#   Actor   Time    Event   
                   shortcut clicked
       L           START_ACTIVITY_TRANSACTION begin
       B           on START_ACTIVITY_TRANSACTION
       A          SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin
       B           on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION
       L         SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end
       A        START_ACTIVITY_TRANSACTION end
       L         ACTIVITY_PAUSED_TRANSACTION begin
       B           on ACTIVITY_PAUSED_TRANSACTION
      A           process starting
      B        process started
      AM       ACTIVITY_PAUSED_TRANSACTION end
      M       main entered
      M          ATTACH_APPLICATION_TRANSACTION begin
      B           on ATTACH_APPLICATION_TRANSACTION
      A          SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin
      B           on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION
      M           SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end
      A        ATTACH_APPLICATION_TRANSACTION end
      M      searchabledictionary oncreate

               item clicked
      L           START_ACTIVITY_TRANSACTION begin
      B        on START_ACTIVITY_TRANSACTION
      A           SCHEDULE_PAUSE_ACTIVITY_TRANSACTION begin
      B           on SCHEDULE_PAUSE_ACTIVITY_TRANSACTION
      L           SCHEDULE_PAUSE_ACTIVITY_TRANSACTION end
      A          START_ACTIVITY_TRANSACTION end
      L          ACTIVITY_PAUSED_TRANSACTION begin
      B           on ACTIVITY_PAUSED_TRANSACTION
      A           SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION begin
      B           on SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION
      M           SCHEDULE_LAUNCH_ACTIVITY_TRANSACTION end
      A        ACTIVITY_PAUSED_TRANSACTION end
      M       wordactivity oncreate
           

說明:

  1. Time 為目前事件與上一事件的間隔,Actor 為消耗這段時間的主體。A:

    AMS

    ;B:

    Binder

    ;L:

    Launcher

    ;M:

    MainActivity

  2. 友善起見,請求啟動子Activity的對象同樣被标記為

    Launcher

  3. Process.start

    的執行時間歸于

    Binder

    ,而該函數傳回直到

    ActivityThread.main

    的時間歸于

    MainActivity

  4. Process.start

    AMS

    MainActivity

    并發執行,時間為 11.1ms,為便于統計這段重合時間歸于

    AMS

  5. 腳本完成了絕大部分計算,仍有部分是手工計算的(這些結果包括行 1-2、行 19-20、行 36-37 之間的間隔)。
  6. 相同時間的 Log 可能會出現亂序(Log 并非原子操作,但時間的正确的),最終結果對這種情況進行了手工糾正。

對這四個主體消耗的時間進行加和,可得到如下時間分布圖:

圖1:主Activity 啟動時間分布(合計:674.3ms)

Android App 啟動過程分析

圖2:子Activity 啟動時間分布(合計:185.6ms)

Android App 啟動過程分析

由圖1可以看出,主Activity 啟動過程中,主要的性能瓶頸由

MainActivity

的建立和切換産生,

Binder

消費的時間非常少。

在圖2中,各部分消費時間相差較小,以

AMS

MainActivity

耗時為主,

Binder

所占時間仍是最少的。

在圖2中,子Activity啟動時間相對主Activity來講已經大大減少。此外,這個過程的時間波動可能與子Activity 的具體類型高度相關。

在圖2中,

Launcher

的時間有所增加。注意這裡的

Launcher

是發出啟動子Activity請求的對象,即主Activity。這說明系統的Launcher程式是有所優化的(響應時間減少了76.1%)。

綜上,

  • Binder

    機制是一種高效的程序間通信機制。它在提供高可靠性和擴充性的同時,并未引入過多的時間開銷。
  • AMS

    提供将Activity與程序分離的機制,其時間也小于MainActivity本身,這樣的開銷是值得的。
  • 系統的

    Launcher

    啟動Activity的速度要高于普通的主Activity。