TraceView使用經驗
在對手機淘寶效能分析和定位的過程中Traceview是使用最多的一個工具在遇到啟動時間長介面切換時間長特別卡頓的時候Traceview是首選工具。如果檢視介面的幀率問題建議還是先使用GPU配置檔案以列表的形式展示在螢幕上這樣可以首先發現這個介面的幀率是否有問題再做後續的排查。
Traceview是Android平臺特有的資料採集和分析工具它主要用於分析Android中應用程式的效能問題。Traceview本身只是一個資料分析工具而資料的採集則需要使用Android SDK中的Debug類或者利用DDMS工具。二者的用法如下
- 開發者在一些關鍵程式碼段開始前呼叫Android SDK中Debug類的startMethodTracing函式並在關鍵程式碼段結束前呼叫stopMethodTracing函式。這兩個函式執行過程中將採集執行時間內該應用所有執行緒注意只能是Java執行緒的函式執行情況並將採集資料儲存到/mnt/sdcard/下的一個檔案中。開發者然後需要用SDK中的Traceview工具來分析這些資料。
- 藉助Android SDK中的DDMS工具。DDMS可採集系統中某個正在執行的程式的函式呼叫資訊。對開發者而言此方法適用於沒有目標應用原始碼的情況。DDMS工具中Traceview的使用如圖所示。
![](https://i.iter01.com/images/15dc3478efb32bc35f7145e6dd0a9563d56648cb98f8479b58a70ce6f2821673.jpg)
在做效能分析的過程中基本都是採用DDMS工具中來啟動TraceView這樣簡單易用隨便哪個地方的程式碼都可以跟蹤。在對android 4.4以上手機點選TraceView按鈕的時候會出現2種方式的選擇對話方塊如下所示
![](https://i.iter01.com/images/810d7a80e5e37b2f4f43b8065ba5e288a2c27052c6978fd05a2f6ec94698ca31.png)
1、Sample based profiling以固定的頻率像VM傳送中斷並蒐集呼叫棧資訊。低版本手機也是採用該方式來採集樣本的預設是1毫秒採集一次。精確度和採集的頻率有關間隔頻率越小會越精確但執行也會相應的更慢。
2、Trace based profiling不論多小的函式都會跟蹤整個函式的執行過程所以開銷也會很大。執行起來會非常的慢不適合檢測滑動效能。
一般情況用第一種預設1000微妙的間隔就足夠了。
另外在Eclipse中或者Android Studio中啟動的DDMS中的這個工具搜尋功能不能使用如果要使用搜尋功能可以通過Android SDK tools下的命令列來啟動這樣就可以搜尋了。
![](https://i.iter01.com/images/a207e4ebf80162521bfad005ec6bb59d946e4d9d00bfdfe93ce7ddfe12ad9480.png)
- Traceview其UI劃分為上下兩個皮膚即Timeline Panel和Profile Panel。
- Timeline Panel左邊是測試資料中所採集的執行緒資訊右邊Pane所示為時間線時間線上是每個執行緒測試時間段內所涉及的函式呼叫資訊。內容的豐富代表該時間段執行的函式多從而可以反應執行緒的繁忙狀態。也可以看出執行緒的啟動時間和結束時間等。
- Profile Panel是Traceview的核心介面其內涵非常豐富。它主要展示了某個執行緒先在Timeline Panel中選擇執行緒中各個函式呼叫的情況包括CPU使用時間、呼叫次數等資訊。而這些資訊正是查詢效能瓶頸的關鍵依據。
- 另外開發者可以在時間線Pane中移動時間線縱軸。縱軸上邊將顯示當前時間點中某執行緒正在執行的函式資訊。
Profile Panel中各列的含義。如下表所示
列名 |
描述 |
Name |
該執行緒執行過程中所呼叫的函式名 |
Incl Cpu Time |
某函式佔用的CPU時間包含內部呼叫其它函式的CPU時間 |
Excl Cpu Time |
某函式佔用的CPU時間但不含內部呼叫其它函式所佔用的CPU時間 |
Incl Real Time |
某函式執行的真實時間以毫秒為單位內含呼叫其它函式所佔用的真實時間 |
Excl Real Time |
某函式執行的真實時間以毫秒為單位不含呼叫其它函式所佔用的真實時間 |
Call+Recur Calls/Total |
某函式被呼叫次數以及遞迴呼叫次數/總呼叫次數 |
Cpu Time/Call |
某函式呼叫CPU時間與呼叫次數的比。相當於該函式平均執行時間 |
Real Time/Call |
同CPU Time/Call類似只不過統計單位換成了真實時間 |
瞭解完Traceview的UI後現在介紹如何利用Traceview來查詢效能問題。
1、可以直接檢視幀率和渲染情況
如上面的TraceView圖皮膚所示顯示了Draw函式的執行情況。在時間線上可以看到前面部分間隔平滑且時間比較短到中間部分開始就開始中斷執行時間也明顯拉長。說明出現了丟幀等情況通過放大時間線可以檢視執行時間較長的draw函式中每一個函式的執行情況從而發現問題。
2、瞭解函式前後的路徑和執行情況
Profile Panel皮膚的函式有Parents和Chindren對於部分有遞迴呼叫的函式還會有Parents while recursive和Chindren while recursive。通過點選Parents和Chindren的各個函式用於跟蹤效能問題也能瞭解這個函式的來龍去脈。以及幾個Parents呼叫了該函式每個Parents呼叫的次數。該函式自己的執行時間以及各個Chindren和他們的執行時間以及本函式Chindren中用到的某個函式A佔據所有呼叫該函式A的分佈比例情況。
3、找出函式所在的執行緒分佈
Profile Panel皮膚的函式點選後在對應上面部分函式時間線上會有相應的指示如下面的括號上下的顏色標記符號該顏色標記符號和Profile Panel皮膚中的該函式前面的方塊顏色對應。如下圖Logger.isLoggable函式點選後從時間線上看到了在main執行緒和Thread-3191執行緒中的分佈情況。
3、CPU定位高負荷函式
通過Incl Cpu Time排序就可以輕鬆發現cpu被哪些函式佔用了。
通過Incl Cpu Time排序可以找到相對耗時的函式在函式排序的皮膚中選中該函式如果在Main執行緒中底部某區間出現了括號則表示該執行緒這段時間執行了該函式。這樣就可以找出主執行緒的耗時函式了。同理也可以查詢某函式在各個執行緒中的分佈情況。
![](https://i.iter01.com/images/2e9e0cf253f292d768d1d295d9a080d65b8ab20d35d0b697dbc3c4e5902a393e.png)
5、檢視部分GC原因和位置
因為安卓2.3以後GC並不會每次都停止其他執行緒因此只能跟蹤到部分停止所有執行緒的GC情況。一般出現GC的時候時間線上會有比較大塊的同顏色的區域點選後就可以定位到函式皮膚區域的GC函式一步一步向parent函式追蹤就可以定位到GC的起因了。如下圖的綠色部分主執行緒在載入資源圖的時候發生了GC。
![](https://i.iter01.com/images/59cc0cb69c1c6d5d5a561e91241ce840b1bfd223d7b726f6a21e7d6a0509a958.png)
6、動畫或者滑動過程是否觸發Layout
動畫和滑動過程中在控制元件呼叫gone或者動態新增刪除重新設定paramsTextView重新設定文字以及重新設定Drawable的時候都會觸發Layout。在ListView的getview過程中它自己阻斷了這個requestlayout自己對子控制元件做了layout的操作所以不會引起整個介面的重新佈局。但是如果在其他時間設定了圖片、文字等就可能導致requestlayout被觸發進而執行onMeasure過程和onLayout過程這樣的話就會大大影響了滑動過程中的效能容易造成卡頓。在滑動過程中或者有動畫的情況下做TraceView跟蹤可以發現是否被觸發了重新佈局。在跟蹤結束中搜尋onLayout或者layout或者requestlayout可以方便找到對應的控制元件。
![](https://i.iter01.com/images/f31d339073ba88c2b8496850fc6d51ee48ea441c78e73d8a4785dae8e8099c6f.png)
![](https://i.iter01.com/images/0a647a190eecc7da9e7409fc0f804adbcea94f95ca2298a5e9960274eaff7cfa.png)
7、找出較小的耗時函式
前面按照Incl Cpu Time排序一下就可以找到較大的效能問題函式但是小的耗時函式就不是通過這種方式來找了。我們把Call+Recur Calls/Total和Cpu Time/Call放到最前面按照Cpu Time/Call排序找出平均執行時間久的函式展開其子函式分析是否存在問題並通過呼叫次數看嚴重的程度。如下圖我們發現社群介面在滑動過程中的TBS提交埋點函式耗時過久進一步跟蹤發現是Hashmap多餘的putall操作。
![](https://i.iter01.com/images/e011ece1d0e5127088e414d6b7c26a673798e91dea6a77d06a87fd2a58aa53d6.png)
8、查詢高頻率呼叫存在效能的點
我們把Call+Recur Calls/Total和Cpu Time/Call放到最前面按照Call+Recur Calls/Total排序檢視執行次數多的隱患函式展開其子函式分析是否存在問題並通過Incl Cpu Time 的CPU佔用比以及Incl Cpu Time 的佔用百分比來判斷嚴重性特別是呼叫次數多的且Cpu Time/Call次數也多的應該重點排查。通過這樣我們就能找到高頻率呼叫函式的效能問題點。我們發現一個簡單的函式但是呼叫次數太多後導致了相對的耗時且這裡只要用到一個寬度只要第一次獲取後儲存該值不需要每次從系統函式中去取這樣就解決了。
![](https://i.iter01.com/images/9e36968a38215559b7a90a79688be49dc1b4ff48fced1a775ff58d1ada0d6cb7.png)
但是有時候判斷一個函式是否嚴重還是需要對系統的瞭解。比如SharedPreferences的apply函式較高頻率呼叫但是其CPU和單次時間都不會佔用多少但是這確是一個效能影響點因為直接commit有阻塞的IO操作apply函式呼叫後程式中有專門一個SharedPreferences的寫執行緒會處理寫入操作而這個寫執行緒此時可能會很耗時。反過來如果看到SharedPreferencesImpl&*run執行緒佔用較高cpu的時候就可以推斷出較多的SharedPreferences的操作了我們應該通過搜尋把apply的呼叫出都找出來。
![](https://i.iter01.com/images/6233e65810c03903e660da58b99e3a3bd89216644974709a1c642bfffd4020f2.png)
9、檢視佈局效能問題
通過Incl Cpu Time百分比排序列表滑動過程中如果看到onMeasure或者onLayout大於25%以上的就應該可以判斷出當前這個介面的佈局效能不佳需要優化了。
![](https://i.iter01.com/images/7ab1123357e538e2251095b7a93d13fa883671aa2d748893b896c4700952b95d.png)
在列表滑動過程中也需要檢查getview這樣的函式的效能特別是佈局複雜的初始化時間會比較久。
![](https://i.iter01.com/images/8eea8caafceb34ac9d60e8c0db9399ec5a9e1e50fc1c750ab84c3a86fb1faf11.png)
![](https://i.iter01.com/images/15ee5f07a47f65a71adc0efeb98d5f6fd0a9b36cb6e2244dcd964c0181f1094d.png)
10、檢視佈局複用問題
在列表滑動的過程中或者廣告Banner控制元件一般的做法都是應該複用佈局提升效能的但有時候因為覺得麻煩有些可能是動態新增的就沒有複用這些view導致在滑動過程中還是會出現infalte佈局的情況影響效能。跟蹤方法是在這個列表已經滑動過的情況下開始進行TraceView這個時候來回滑動不應該出現infalte如果出現了就是複用出現了問題。下圖中我們對“我的訂單”介面做了跟蹤發現有動態inflate button導致每次都額外增加了時間影響效能。
![](https://i.iter01.com/images/2566db59a21e6ca3201abcd1d1b2e322ea01d75d510b603dce8d78533e13e849.png)
還有一種判斷方法就是在進入介面的時候找出LayoutInflater.createViewFromTag函式找出它數量以及parents呼叫方檢查是否有問題。
![](https://i.iter01.com/images/b75db3c2581e94cf85b3859fd0dce236ba08270fcf894a98f4c2f8a733c6f732.png)
11、判斷佈局巢狀過多或者過於複雜
我們把Call+Recur Calls/Total和Cpu Time/Call放到最前面通過View/ViewGroup的draw呼叫次數和遞迴呼叫次數來判斷佈局的層級過多或者佈局Layout太多。也可以通過buildDisplayList函式的呼叫和遞迴呼叫次數來判斷佈局的層級過多或者是Layout太多。
![](https://i.iter01.com/images/dbc4aa196dd2b1c014bfada50f45d3806b670fec476a72db957a14a77f653b18.png)
12、查類的初始化效能
我們把Call+Recur Calls/Total和Cpu Time/Call放到最前面通過Cpu Time/Call排序找到一些類的建構函式<init>判斷類的初始化效能。類的初始化過程如果太久特別是在主執行緒中會影響效能而這個又是一個容易忽略的問題因為類的初始化過程可以簡單也可以複雜複雜的可以做懶載入來優化。如果呼叫次數多的那就更應該優化或者做複用。
![](https://i.iter01.com/images/9f8e6f4139cf838e4f17fed052e096a2a012e1fa7aa6c015ff15d13965c1ce0a.png)
13、排查字串問題
把Call+Recur Calls/Total放到前面在搜尋字串相關的一些StringBuiler類或者StringBuffer類還有append方法以及enlarge方法來檢視當前的字串問題。找到呼叫方去掉不必要的字串拼接和擴容來提升效能。
![](https://i.iter01.com/images/9c698be3e439c620029d4905f88180a7d93ae4ae8bdbb9480c4a4660ded41a63.png)
14、未開啟硬體加速
檢查繪製函式如果發現是drawSoftware那就是未開啟硬體加速影響了幀率。
![](https://i.iter01.com/images/a8130681dcd1747a29cdb3d9df91dfb9d9b62eae5cad3cec5eeeed65b52ff2dc.png)
15、排查整合的問題
有時候整合需要多個包可能會漏掉其中一個這一個時候通過TraceView呼叫分析自己的某個函式但是和自己的預期不一樣明明已經改過了為什麼還會這樣這個時候可能就是打包的時候沒有引用到正確的包。
16、排查自己寫的函式是否符合預期
有時候自己寫的函式如字串問題會被編譯器做一些優化或者不太注意用了很多+號導致了很多StringBuilder物件的分配這個時候通過TraceView我們可以發現在該函式下建立了多少個StringBuilder和以及擴容的問題。通過呼叫次數來判斷對效能的影響如果是頻率比較多的函式就應該去優化這些問題。
![](https://i.iter01.com/images/0c916792b8b5d4e974d4312f635d8bb7a0207f7aa08b8fed2cd9a0dea9d25e15.png)
17、發現可複用物件
在對一些頻率較高的函式的子函式分析過程中我們可以去看是否每次這個函式呼叫的時候都會去建立這些物件如果是那可以考慮一下是否可以對這些物件做複用。如下圖發現這個重入鎖物件應該做複用。
![](https://i.iter01.com/images/a9961dd0f5f7425b307b6d94646f4c6ddc4a6c6e0fa38b0df827b182fba1cb83.png)
18、判斷主執行緒長時間等待原因
時間線上主執行緒長時間空白可能是受其他因素的影響比如安全軟體對IO的監控用了鎖等待某個資源或者CPU太忙了沒有時間片來分配。下面第一張圖是因為安全軟體對IO的監控用了鎖等待某個資源導致主執行緒執行效能問題第二張圖則是由於其他現場太多太忙了導致主執行緒CPU分配不到時間片。
![](https://i.iter01.com/images/e05a3c7c23d5331f9b83ba6aa736d8e86989b1c7ebe34b133bdfd6ed740250ae.jpg)
![](https://i.iter01.com/images/038c80d39bf1c38dfe543760903abdf4a3c4477631dd7779c3af0af6d28f0fd1.jpg)
19、靈活運用時間線找出根源
在安卓程式碼中我們不建議主動呼叫System.gc方法來觸發GC但是在檢測首頁滑動過程中LogCat中還是定時出現了GC_EXPLICIT的垃圾回收資訊。通過啟用TraceView的跟蹤發現了呼叫System.gc的函式位置但是向上跟蹤後最終只能跟蹤到一個執行緒池的run具體這個執行緒的run由誰呼叫沒法繼續跟蹤了。這樣只能通過時間線上再去找問題通過滑鼠放在時間線上從後到前簡單掃描了一下時間線並未發現和taobao,ali等包名的函式為了繼續排查只能放大時間線來發現線索通過放大時間線皮膚呼叫函式也會變得越來越細膩最終在呼叫gc前面部分位置找到了com.alibaba.mobileiim.channel.http.httpwebTokenCallback的函式呼叫從而定位到問題所在。
![](https://i.iter01.com/images/ad9a739d9ae195b73e0d788169c7ee910aa1cc46d67316c2ea67ed9381884e4a.png)
![](https://i.iter01.com/images/a27a94d6a01998fd0918216df49621d344b1f203b75423ab4e01ca5b5a451b96.png)
20、瞭解一些函式的效能問題如字串函式格式化函式等
通過佔用cpu百分比呼叫次數平均呼叫時間可以觀察到一些系統類實現的函式有效能問題在高頻率下不應該呼叫。
![](https://i.iter01.com/images/a442afdc8ecf21e40c66e97890f102c2dc5644d8672d287daf4a98d724354703.png)
![](https://i.iter01.com/images/6ca12d361ac64a3b4440bc1c50e1effb4d257a0285f5d5831db72b833e47e9f3.png)
![](https://i.iter01.com/images/18219fa67eb889a42876e4127335c831180f02df56e30845cc28464e1a7036dc.png)
21、如果你對JAVA相當熟悉甚至可以通過這個軟體發現一些程式碼上的問題
在分析一個高頻率函式的時候發現該函式包裝了一個subString方法但是子函式中卻多了一個String類的建立。待著問題檢視了實現程式碼發現該函式確實實現有問題。String是不可變物件source.substring函式本身就會返回指定的sub字串內部會new一個string外部不需要再new string這樣多了一次物件的分配。
![](https://i.iter01.com/images/4ce60cb11f4318aac00a6a22f44de22008e32e6426f5481c3cad1ac2b156b889.png)
檢視該檔案的這個函式
public static String substring(String source, int start, int end) {
if (end <= 0) { new String(source.substring(start)); } new String(source.substring(start, end));
}
22、一定不要忘了在各個介面的靜默狀態做跟蹤特別是有動畫的介面
在有廣告條輪播等動畫的介面尤其要注意像首頁、社群等介面都發現了在廣告條移出螢幕外的時候還有定時重新整理廣告的問題這個會影響效能和耗電。有時候看程式碼已經用Handler的removeCallbacks(this)介面移除了但佇列中可能還有其他的定時例項會重新啟動這個定時removeCallbacks只是在佇列中移除了這個例項相關的訊息。替換成removeCallbacksAndMessages(null)函式移除全部等候執行的訊息後才解決了該問題。
TraceView也是一個在介面切換到後臺被其他程式覆蓋等情況下檢查程式中仍再執行的執行緒等問題的首選工具。
![](https://i.iter01.com/images/f0c955d280248c6c33dbd57eeb8a692d062b4d690d23429bcbf388a72f1d7213.png)
以上是我常用的TraceView效能跟蹤的一些方法當然隨著使用的嫻熟你會發現它的功能並不止這些而且用的熟練後很容易就能找到影響效能的關鍵點。當然這個函式也不是都能排查所有的效能問題有時候還是需要結合其他函式一起來使用才能更好的解決效能問題這個將在後續的文章中來介紹。