寫在前面

最近工作轉到Android 效能優化方向，剛轉過來，相關經驗缺乏，紀錄一個目前讓人惱火的問題。非常遺憾，本文到目前為止還未能提供解決問題的優化方案，也沒有明確定位到導致效能問題的瓶頸所在。就像解數學題一樣，花費了大把時間，然並卵。之所以寫它，兩個目的：
- 這個過程中，自己還是有一定收穫的，且做紀錄。
- 丟擲問題，希望能與更多人一起討論效能優化的方法。

問題描述

冷啟動email應用相對於參考機慢。
參考機OS: AndroidM
問題機OS: AndroidN
參考機平均耗時：1.7s
問題機平均耗時：2.0s

問題分析

Email應用版本自身的影響

先檢視email版本是否相同，使用命令:

adb shell dumpsys package com.tct.email|grep version

得到問題機email版本—> versionName=v7.0.4.1.0312.0_0228
參考機email版本—> versionName=v5.2.10.3.0214.0
參考機與對比機email版本不同.因平臺Email應用與Exchange應用聯絡緊密，一併檢視Exchange版本。
問題機exchange版本—> versionName=v7.0.4.1.0312.0_0228
參考機exchange版本—>versionName=v5.2.10.3.0214.0

使用用命令：

adb shell am start -W -S com.tct.email/.activity.Welcome

檢視Email的啟動時間
為了方便統計，編寫一個簡單的指令碼封裝上述命令。指令碼簡短，在此貼出。

#!/usr/bin/env python
'''
@author: [email protected]
@summary: this script use to test launch activity time
'''

from commands import getoutput
from time import sleep
from __builtin__ import
 
 int

LAUNCH_PACKAGE = 'com.tct.email'
LAUNCH_ACTIVITY = 'com.tct.email/.activity.Welcome'
TEST_COUNT = 5 ＃測試次數
SLEEP_TIME = 10 #每次啟動的時間間隔

LOG_LINE = "**************************************************"

def getVerInfo():
    getVerCmd = "adb shell dumpsys package %s | grep version" % (LAUNCH_PACKAGE)
    verinfo = getoutput(getVerCmd)
    print LOG_LINE
    print "Test APK version info is:"
    print verinfo.strip()
    print LOG_LINE

def getLaunchTime():
    getLaunchTimeCmd = "adb shell am start -W -S %s |grep TotalTime|awk '{print $2}'" % (LAUNCH_ACTIVITY)
    totalTime = 0
    for i in range(1, TEST_COUNT + 1):
        time = getoutput(getLaunchTimeCmd)
        print "%s lunch time is %s" % (i, time)
        totalTime += int(time)
        if (i < TEST_COUNT):
            sleep(SLEEP_TIME)
        i = i + 1
    average = totalTime / TEST_COUNT
    print "%s launch time average is %s" % (TEST_COUNT, average)

def main():
    getVerInfo()
    getLaunchTime()

if __name__ == '__main__':
    main()

其輸出結果如下：

從結果看對比機明顯好於問題機，那麼這種差異是否由apk自身版本不一致導致呢?
為了回答這個問題，將問題機的emal安裝到參考機再次測試。
使用命令：

adb shell pm path com.tct.email

找到email的apk路徑
使用命令：

adb pull /system/app/Email/Email.apk

將問題機的Email拉出來。
使用命令：

adb install -r Email.apk

將剛拉出來的Email安裝至參考機,此時再次測試得到如下表格:

為了直觀表述，根據上述資料生成柱狀圖如下：

從上述柱狀圖看Email應用的版本對最終測試資料的影響很大，本以為可以確定是APK版本差異導致的問題，然而最後測試“問題機＋參考機Email”的組合發現啟動依然慢，資料沒有整理，就不貼出來了。

由於無法確定是APK版本差異導致的問題，因此該問題就劃歸在平臺側分析。

平臺影響

cpu差異

通過命令：

adb shell getprop ro.product.cpu.abi

可以看系統是32還是64位
問題機：armeabi-v7a,armeabi
參考機：armeabi-v7a
通過命令：

adb shell cat /proc/cpuinfo

檢視cpu資訊，二者cup一樣均為4核：

Hardware    : Qualcomm Technologies, Inc MSM8909
Revision    : 0000
Serial      : 0000000000000000
Processor   : ARMv7 Processor rev 5 (v7l)

排除CPU影響。

記憶體差異：

通過命令：

adb shell getprop dalvik.vm.heapstartsize

檢視系統分配給應用冷啟動的初始堆空間
問題機：16m
參考機：8m
排除該項。
通過命令：

adb shell cat /proc/meminfo

檢視系統總體的記憶體設定情況，得到下圖：

利用excel生成柱狀圖直觀的看看各項值的差異,內容較多，只擷取差異最大的一部分。

可以很直觀的看到參考機和問題機上Committed_AS差異較大，其他各項二者相當，問題機都略高於參考機。尤其總記憶體大小問題機還比參考機高。好多項的具體含義我也不清楚，直觀感覺差異項最大的最可能包含著潛在的問題。
那麼這個 Committed_AS是表徵什麼的呢？

原來Committed_AS 表示所有程序已經申請的記憶體總大小，（注意是已經申請的，不是已經分配的），如果 Committed_AS 超>過 CommitLimit 就表示發生了 overcommit，超出越多表示 overcommit 越嚴重。Committed_AS 的含義換一種說法就是，如果要絕對保證不發生OOM (out of memory) 需要多少實體記憶體。
在打個比方，餐館有10張餐桌，假設1張餐桌只能接納1組客人。那麼一下來了100組客人，Committed_AS的含義餐館至少需要100張餐桌才能保證這些客人都能及時用餐。透過它能看到餐館的忙碌程度。

因為問題機的MemTot是大於參考機的，因此該項的差異不太可能是平臺側影響效能的主因，故而排除。

通過命令

adb shell getprop|grep dalvik

檢視問題機dalvik預設配置

[dalvik.vm.appimageformat]: [lz4]
[dalvik.vm.dex2oat-Xms]: [128m]
[dalvik.vm.dex2oat-Xmx]: [512m]
[dalvik.vm.heapgrowthlimit]: [128m]
[dalvik.vm.heapmaxfree]: [8m]
[dalvik.vm.heapminfree]: [512k]
[dalvik.vm.heapsize]: [256m]
[dalvik.vm.heapstartsize]: [32m]
[dalvik.vm.heaptargetutilization]: [0.75]
[dalvik.vm.image-dex2oat-Xms]: [128m]
[dalvik.vm.image-dex2oat-Xmx]: [128m]
[dalvik.vm.isa.arm.features]: [default]
[dalvik.vm.isa.arm.variant]: [cortex-a7]
[dalvik.vm.stack-trace-file]: [/data/anr/traces.txt]
[dalvik.vm.usejit]: [false]
[dalvik.vm.usejitprofiles]: [false]
[dalvik.vm.zygotemaxfailedboots]: [5]
[persist.sys.dalvik.vm.lib.2]: [libart.so]
[ro.dalvik.vm.native.bridge]: [0

這裡各項預設值跟參考機相比也沒發現異常。
猜測因記憶體差異導致的問題到這一步未找到有效證據。

I/O 讀寫速度差異

利用命令

adb shell vmstat -n 1

檢視Email啟動瞬間系統層的變化。得到如下輸出。關於vmstat的資訊，可以點選這裡

===================================問題機=====================================
procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa
0  0      0 269536  70424 1009964   0    0     0     0    0  388  1  1 99  0
*2  0      0 271228  70432 1009956   0    0     0   104    0 2653 14 17 68  0
*6  0      0 252056  70444 1010004   0    0     0   160    0 8102 35 23 42  0
0  0      0 248168  70444 1010004   0    0     0     0    0 2487 11  3 86  0


===================================參考機=====================================
procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
0 0 29596 89580 55240 781332 0 0 0 0 0 829 2 2 97 0
*6 0 29596 90784 55268 781304 0 0 0 800 0 4580 0 0 0 0
*1 0 29596 74996 55268 781316 0 0 0 128 0 5332 33 12 55 0
0 0 29596 76220 55268 781368 0 0 0 0 0 2118 0 0 100 0
以上輸出開頭加*的行是啟動Email時對應的變化(*是為了方便描述，自行新增的)。
下面來挨個過一遍。
procs欄裡的r(running),它表示執行佇列中的程序數，即多少個程序分配到了CPU. 二者相差不大，看不出問題。
b(blocked) 被阻塞的程序數，二者均為0，表示沒有程序被阻塞。
memory欄裡的swpd。
特意在linux論壇查了下其含義，看看其中某段解釋：

Note that a swap usage rate of zero is highly desirable because it means that your existing RAM can handle the load that’s being put on it without resorting to writing memory pages to disk. In other words, anytime your system has to access swap, you will be taking a huge performance hit – access times in RAM are measured in nanoseconds; access times on hard drives are measured in milliseconds. That’s about 6 orders of magnitude worse, and you should avoid it if at all possible.
To say it another way, Linux treats swap space as a resource of last resort. If the demands you are putting on your machine are such that RAM is overloaded and cannot handle it, then your system will write out memory pages to disk, but as mentioned this is only done when RAM is entirely overloaded. Back in the days were 64Mg was considered leading edge, it was pretty common for swap to be called into service, but these days, where 256Mg if not 512Mg of RAM is standard, it’s increasingly infrequent that swap gets used.
Overall, I’d consider zero swap usage to be a compliment to how you’ve set up your system. That being said, reserving some swap space (256Mg max, regardless of the RAM) is a useful thing, just in case. – J.W.

swpd表示已經使用的虛擬記憶體大小. 如果大於0，表示手機實體記憶體不足,需要將部分記憶體內容轉移到磁碟上。如果不是應用記憶體洩漏的原因，就是當前後臺執行的任務過多了。問題機為0，這個是個好的現象，說明問題機至少不存在記憶體吃緊的情況。

memory欄裡的free表示空閒記憶體大小，同樣問題機大於參考機，這也是好現象。
memory欄裡的buff/cache兩臺機器也沒有異常值排除。

swap欄裡的si,表示每秒從磁碟(disk)讀入的記憶體大小(/s). 如果這個值大於0，表示實體記憶體不足或者記憶體洩漏，需要查詢耗記憶體的程序。
swap欄裡的so,表示每秒從記憶體寫入磁碟的記憶體大小，他的資料不為0，表示當前記憶體不夠用，需要將部分記憶體的內容騰出來到磁碟空間。
上述兩項值在問題機和參考機上都為0.說明這裡不是問題所在，故而排除。

io欄裡的bi表示手機裡塊裝置每秒接收的塊數量，對應寫操作。而bo正好相反表示每秒傳送的塊數量，對應讀操作。這裡看到bi均為0，表示問題機和參考機在啟動Email的階段都沒有寫入操作，但bo值參考機明顯大於問題機。這裡可能是個問題，想象這樣一個場景，啟動Email時需要讀取執行的code段，而問題機一次讀取的code段少於參考機，那麼相應的問題機在這段時間可執行的code段也就少於參考機,進而有可能影響最終的啟動速度。
為了驗證該猜想，調整I/O讀寫速度在來看該問題。
使用命令：

adb shell echo 1024 > /sys/block/mmcblk0/queue/max_sectors_kb

將max_sectors_kb擴大一倍，之前是512. max_sectors_kb值代表傳送到磁碟的請求數。然而結果依然沒有提升。想不通為何。

system欄裡的in(interrupts) 表示在delay的時間內（預設為1秒）系統產生的中斷數，二者均為0，排除
system欄裡的cs (context switch) 表示在delay的時間內（預設為1秒）系統上下文切換的次數. 例如程序切換，要進行上下文切換；執行緒的切換，要進行上下文切，程式碼執行進入核心空間，上下文也要切換。這個值越小越好，太大了要考慮降低執行緒或者程序數目。因為上下文切換很耗資源，次數過多表示CPU大部分浪費在上下文切換而不是執行程式內容，CPU沒有充分利用。該項資料參考機是好於問題機的。

cpu欄裡的us表示使用者空間執行任務所佔CPU的時間百分比。看不出問題排除。
cpu欄裡的sy表示kernel空間執行任務佔用的CPU時間比 ， 如果太高，表示系統呼叫時間過長，例如IO操作頻繁。這裡問題機明顯高於參考機，提示存在問題。
cpu欄裡的id表示空閒CPU佔用的時間比。一般來說，id + us + sy 接近 100%
cpu欄裡的wa表示CPU等待IO完成的時間佔比，該值若大，對系統的流程性衝擊大。問題機和參考機都為0，看不出問題。

寫在最後

問題還在持續分析中，如果看到這篇文章的你，有什麼好的排查方向，或者排查方法，歡迎一起討論。