微信讀書 iOS 質量保證及性能監控
在實現需求的同時,能寫出既優雅性能又高效的代碼是每個開發者都在追求的目標,但是在實際開發中,隨著每個版本需求的迭代,功能變得越來越復雜,加上開發者的意識不夠或者一時疏忽,日漸復雜的工程很容易產生或多或少的問題。在使用微信讀書的過程中,我們也碰到過app隨機丟失動畫、用戶反饋app卡死、用戶投訴看不了書籍等等的問題,這些問題都嚴重影響使用,也會降低產品口碑,因此我們開發了一些監控工具來解決這些問題,在這里總結和分享一下。
先來看看app的結構,如下圖:
微信讀書主要分為5層,由下至上分為:
- 網絡層:負責和服務器通訊,使用http協議獲取數據。
- 數據層:存儲用戶的數據,包括內存cache和sqlite db。
- 業務層:包含各種業務邏輯,比如書籍下載、排版等。
- UI數據層:負責提供UI層所需要的數據,UI只和這層打交道。
- UI層:包括ViewController和View,處理用戶的輸入。
當UI需要數據來渲染時,會向UIDataSource獲取數據,UIDataSource首先是通過Manager查詢內存cache和db看有沒有數據,有的話就會直接返回,同時也會發出網絡請求和服務器同步數據,再使用數據層的接口存到數據庫,最后回調給UI去重新獲取本地數據來渲染。每一個層都是相互獨立,用戶遇到的每一個問題都對應著每一層,下面說說我們在每一層遇到了什么問題,以及做了什么工作來解決它們。
對網絡層成功率的監控
網絡層使用NSURLSession對象向服務器發送請求后,要先經過公司統一網關TGW,然后經過代理最后再到CGI處理,最后返回JSON數據,流程較長,而JSON數據也包括業務的錯誤碼。以前開發QQ郵箱時會遇到聯不上網、會話過期、返回的數據格式有誤、中了反垃圾邏輯等等的問題,而每天遇到這些問題的人次應是固定在某一個范圍的,否則就表示app或者服務器不穩定,所以微信讀書很早就開始統計網絡請求的成功、失敗率,了解所有錯誤碼的分布情況。
剛開始時,微信讀書對每一個CGI請求返回的錯誤碼都收集上報然后再統計出人數和次數,后來發現這樣統計失敗率達到30%之高,影響判斷,因為有兩個錯誤碼比較特殊,分別是-1009沒有網絡和-1001超時,App在沒有連網時也可以繼續使用緩存數據來讀書,所以無網絡比較正常。超時是連接服務器超時,可能是app發起請求后就被切換到后臺了被掛起了,或者在后臺被push喚醒然后發起請求,但很快被系統掛起。后來我們把-1009和在請求期間有切換到后臺并且花費了120秒的-1001都作另外統計,真正的失敗率變得更小,這樣就方便看出真正錯誤的分布情況。
以下表格就是某一天網絡請求的統計結果:
從上面這個統計結果可以發現兩個問題:
第一是/store/recommend的次數失敗率突然飆高,點擊可查看具體的錯誤碼,如下圖,主要是-2501這個錯誤碼居多,通過查看代碼和詢問后臺同事就知道是最近新需求上線導致的問題了。
第二個是多了莫名其妙的url,app的某些請求被重定向了,原因可能是DNS被劫持了,我們正在接入HTTPDNS來解決這個問題。
整個發現問題、查找原因過程是很方便的。目前這一塊還沒有加上自動監控,還需要人為地觀察,一般需要持續觀察這個統計表的情況有:
- app新版本上線后
- 下發補丁包后
- 后臺新功能上線后
- 活躍用戶等數據出現異常時
- 用戶投訴
臨近1月1日蘋果要求將http請求切換到https的日子,很多app或者服務器都需要進行改造,網絡層成功率的統計顯示十分重要,當遇到問題時,我們都會先看網絡請求是否出現大面積的失敗來定位問題,如果是網絡層請求失敗可以根據錯誤碼來查找原因,否則就要在其它模塊找原因了。
數據層的性能監控
從RDM的卡頓監控結果看,我們發現了不少卡頓都是發生在數據層,但是看到了卡頓堆棧我們也很無奈,因為當我們自己根據堆棧去重現的時候又不會卡,這種跟特定數據有關的卡頓很難重現,源碼太多流程太長,單純從審查源碼來找出這些原因也是不現實的。數據層就像一個黑盒,接收輸入參數然后輸出數據,如果我們將數據層每一次sql執行所需要的時間都列出來,那我們就知道是什么操作最耗時了,于是我們開始了數據層的監控工作。
我們使用的數據層框架是GYDataCenter,大概的工作流程是這樣的:
數據層主要由內存cache和sqlite組成,每一個db對應一個Cache隊列和DB隊列。業務層每個業務的處理可能在不同線程,當需要數據時通過DataCenter的接口將任務同步放到Cache Queue,然后等前面的任務完成。當Cache任務執行時,如果在cache就有數據就可以立即返回,否則需要查詢sqlite,將任務放入db queue然后等待執行。當查詢到數據庫的數據時,將其轉換成對象然后逐步callback回去,最終回到業務層。所以一次sql的完整操作是要經過等待cache隊列 -> 放入cache隊列執行 -> 等待db隊列 -> 放入db隊列執行這四步,而我們需要做的就是記錄這四步的時間以及對應的sql。
在實際中,我們發現這些操作的數量非常多,所以最后我們沒有將每一次的操作都記錄,只是記錄超過平均執行時間的sql操作。
統計出來的結果如下圖所示,可以按4個時間來排序:
可以對比每個版本的耗時情況:
有了這份統計數據,有以下好處:
- 打開數據層這個黑盒,對整個app的所用到的sql一目了然。
- 可以根據db執行時間進行排序,找到耗時最多的sql,然后進行優化。
- 找到等待cache隊列最長時間的sql,看它在等待誰(目前只能根據源碼查找這一等待序列),然后進行優化調整。
- 可以查看某一條sql語句,對比各個版本的耗時情況,這樣能夠持續監控性能,方便我們縮小問題發生的時間范圍。
經過一段時間的監控,我們發現了一些寫得不合理的并且很耗時的sql,比如
UPDATE WRUser SET isNewFollower=?
這條語句不合理之處在于沒有了“WHERE isNewFollower=0/1”,沒有了WHERE條件就相當于對全表做了一次讀寫操作,當User比較多的時候會比較慢。
SELECT itemId FROM WRReview WHERE (type & ?) > 0 AND timelineRank <= ?
這條語句不合理的地方在于將“type & ? > 0”放在前面,因為位運算是不能使用索引來優化執行的,需要全表掃描一次,應該將“timelineRank <= ?”放在前面,因為它能使用索引優化,如果不滿足這個條件,也不會執行后面的“type & ? > 0”。
UPDATE WRNotification SET isRead=? WHERE notificationId <= 678
這條語句不合理的地方在于最后面的“678”沒有使用“?”,如果使用“?”這種參數綁定的方法,sqlite就不需要重新編譯這條sql,從而節省時間。
有了數據層的監控,不合理的sql語句都被暴露出來,在1.4.5版本,類似第一種沒有寫WHERE條件的UPDATE語句還是比較多的,它們相當耗時,雖然是在子線程UPDATE,但是從上圖可知當子線程在執行任務時,如果主線程訪問數據庫也是需要等待Cache、DB隊列,從而發生卡頓,也引起了很多用戶的投訴。
改善了相關sql后卡頓率有所下降,下圖是RDM統計出來的ANR(Application Not Responding)率,ANR率是在主線程卡頓3秒的人數占聯網人數的比例,按天計算,越小越好。1.4.5版本卡頓率平均在0.93%,1.4.6.299平均在0.63%,有30%的提升。
單純優化sql語句還不能解決所有問題,但根據這些耗時統計,比較慢的操作都是集中在3個表里,它們要么存在位運算字段因此不能使用索引優化,要么因為字段太多,我們后續可能會進行拆表再觀察。
UI數據源監控
UI數據源對象是負責為UI的渲染提供所有數據,它會讀取本地cache、DB的數據,或者發送網絡請求來同步數據。
以前曾經遇到這個問題:
當一條線程在遍歷數組,另一條線程又在修改它時會Crash,因為數組不是線程安全的。程序中存在很多可變數組,雖然目前還找不到方法來查找所有這種多線程讀寫的問題,但是對于我們的UI數據源還是有辦法排查一部分問題的。這是得益于微信讀書UIDataSource都有固定的模式:
WRBookMarketDataSource是書城的數據源,真正為UITableView提供數據的是它的成員 _allBooks ,如果需要多線程訪問這個變量就要加鎖,但最方便的做法是統一都在主線程訪問這個變量。但寫代碼一不注意就會在子線程更改了 _allBooks ,而我們可以做一些事情來防止這件事發生。我們只需hook了UIDataSource的alloc、NSMutableArray的add等方法,當調用NSMutableArray的add方法時,去遍歷所有UIDataSource對象,通過class_copyIvarList、valueForKey函數把所有的成員變量都找出來看看是否為當前的NSMutableArray,通過NSAssert確保當前在主線程,否則在debug模式下會crash提醒開發者修改。通過這種方法能確保操作UIDatsSource的NSMutableArray成員對象一定在主線程操作。
UI主線程監控
1. 防止子線程訪問UI
UIKit的大部分對象都不是線程安全的,所有繼承自UIResponder的類都需要在主線程操作,如果在子線程更改了這些UI對象就會導致未知道的行為,比如隨機出現丟失動畫、頁面錯亂甚至crash。可以嘗試一下以下代碼,在子線程調用100次后,很可能會導致整個app丟失動畫。
UIImageView *imageView = [[UIImageView alloc] initWithImage:image];
為了防止在子線程操作UI,我們在開發階段hook掉UIView、CALayer的setNeedsLayout、setNeedsDisplay、setNeedsDisplayInRect:三個方法,當調用這三個方法時判斷是否在主線程,如果不在主線程調用就讓程序crash,在crash堆棧能看出是哪里的問題。
2. FPS監控
在開發過程中,有些時候我們自己也會遇到卡頓,但很難重現,錯過了現場比較可惜。所以我們弄了一個FPS監控條,通過CADisplayLink來獲取屏幕刷新頻率,在使用過程中就能即時知道什么頁面流暢什么頁面會卡頓,如下圖在右上角一直有一個view顯示fps的變化,當fps低于30的時候,就會捕獲所有線程堆棧,然后右上角的view會給出紅色警示,可點擊查看具體的堆棧信息。如果在真機,反解堆棧還需要另外的工作,Demo可參考 這里 。
這種做法的好處是當自己在使用過程中,如果碰到了卡頓,能第一時間知道是什么場景下發生的,而且知道堆棧大概是什么,當下次碰到現網用戶有類似的堆棧卡頓的時候,就能很快反應過來是哪里卡了,這樣能夠減少很多查找問題的時間。比如下圖就是在使用過程中,app突然之間卡住了一下,fps也降低了,好奇的點開右上角的view,可以看出是在主線程解壓字體壓縮包導致的。
3. 線上用戶監控
線上用戶的卡頓監控是使用RDM sdk來監控的,原理是通過RunLoop的幾個Observer來確定主線程是否卡住了,具體原理請參考老譚筆記。當主線程的RunLoop執行時間超過3秒就會捕獲所有線程的堆棧,然后上報給服務器。通過幾個版本的使用,這種方法確實能夠發現很多卡頓問題并且堆棧也很清晰,也便于我們定位問題。
除此之外,我們還結合RunLoop和用戶點擊流來監控頁面的流暢程度。
比如下面這個統計就是首頁四個tab切換的耗時統計:
當碰到這種頁面切換卡頓時,我們會懷疑是不是隨著用戶的使用時間越多,本地存儲的數據越來越多導致數據處理邏輯變慢的,因為我們進入每一個列表時都會在主線程讀取本地數據來渲染,如果數據多就會卡。所以我們的做法是制造很多測試數據來進行壓力測試,可以是向db插入測試數據,也可以攔截網絡層返回測試數據,通過這種方式來確定是不是頁面切換卡頓是否和數據量有關,如果是的話,會采取分頁拉取,預加載等方式去優化,否則還需要獲取詳細的堆棧,這將會在后續補上。
業務實時監控
在幾個月前,微信讀書用戶反饋系統突然之間收到了很多投訴,對某些書籍app總是顯示章節加載失敗,始終不能閱讀,但是從后臺監控來看是沒有異常的。后來經過一輪排查才知道是書籍內容出問題,而這個問題已經出現一天多了,已經影響很多用戶。為什么后臺沒有發現異常呢,這是因為是書籍內容出了問題,從server端是很難知道這種錯誤的,只有app端在處理這份數據時才容易知道問題。這個問題給我們一個警醒,我們的app端監控存在不足,不能第一時間發現問題,我們需要對一些關鍵業務補上監控。
1. 書籍下載和渲染實時監控
閱讀書籍是微信讀書的主要功能之一,我們需要確保閱讀流程任何一個環節都沒有發生問題。閱讀一本書需要經過的流程有下載章節 -> 解壓數據 -> 存儲 -> 讀取章節 -> 解密 -> 解析 -> 渲染,我們現在對每一步都加了實時監控,一旦有問題發生,運營系統能在幾分鐘內發出警報,第一時間通知相關人員。
2. epub亂碼監控
書籍內容出現亂碼也是嚴重影響閱讀的問題,我們也收到好幾例這樣的投訴。亂碼的原因有可能是書籍本身就不是用UTF8編碼,有可能是文件在傳輸或者解壓過程中丟失了部分字符,幸好UTF8編碼是有規律的,所以我們在排版的時候會檢測這些字符是否用UTF8編碼,如果不是的話就會上報。
3. 想法下劃線位置
閱讀過程中可以對文中內容劃線寫想法然后分享,但是當書籍需要從txt升級到epub時,需要轉換下劃線對應的位置,開發初期我們經常遇到點擊別人的想法但下劃線對應不上的問題,后來也是遇到一個問題解決一個,現在我們已經針對這個問題對線上用戶加上監控,統一處理問題。
以上三個只是業務監控的幾個例子,統計能幫我們發現問題,也為我們決策提供很好的依據。我們業務層監控的思路就是如果遇到問題,不管是自己發現的,還是用戶反饋的,把它解決之后要衡量這個業務的重要程度,出現問題的幾率和后果,如果認為比較重要都會想辦法對相關流程加上監控,希望通過這種方法能及時發現問題。
統計Assert斷言
在開發階段,我們經常加上 NSAssert(NO, desc, ...) 這樣的代碼來保證當程序運行到這里時是完全符合預期的,否則會拋出 NSInternalInconsistencyException 異常并在當前行crash然后在Xcode看到堆棧,但是在發布環境下這些Assert是默認不生效的。我們在發布環境也統計Assert有兩個原因:
- 我們封裝了NSMutableArray等容器類的方法,所有的方法變成 safeAddXXX 、 safeInsertXXX 等,對于 nil object我們是沒有調用真正的 addObject: 方法的,這樣能夠防止crash,但可能會引發其它問題,所以我們需要知道這種情況有多少。
- 有時候命中了某些Assert是比較嚴重的。
如何捕捉所有的Assert呢,iOS為我們提供了一個叫 NSAssertionHandler 的類,一旦中了斷言就會拋到這里處理,但它是線程相關的,每個handler只對應特定線程,而我們需要的是捕捉所有線程的Assert。第二個方法就是重寫NSAssert宏,但這樣替換系統的定義可能會引起未知問題,所以我們只能采取第三種方法,自己包裝NSAssert:
#define GYAssert(condition, ...) if (!(condition)) {GYLogger(…); if (assertCallback) assertCallback(__FUNCTION__, __LINE__, __VA_ARGS__);} NSAssert(condition, @"%@", __VA_ARGS__); [GYLogger setAssertCallback:^(const char *, int, NSString *, ...) { log(func, msg...); dumpStack(…); }];
這樣定義之后,需要將每個地方的NSAssert替換為GYAssert。其中log函數會記錄相應的消息,比如bookId,dumpStack就是獲取當前所有線程的運行堆棧,我們是使用plcrashreporter這個庫來獲取堆棧的。
在開發中,我發現每一次堆棧都有大概60KB,如果每次都上報就太耗費流量了,所以考慮到用戶流量問題,在實踐中,我們并不會每一次中斷言都會上報堆棧,我們會判斷堆棧是否已經上報過。
那么怎樣判斷堆棧是否已經上報過呢?其實堆棧都是有規律的,比如下面這個堆棧:
0 WeRead 0x0000000100b19834 WeRead + 10770484 1 WeRead 0x0000000100b19448 WeRead + 10769480 2 WeRead 0x0000000100b268dc WeRead + 10823900 3 WeRead 0x000000010060e7d4 WeRead + 5482452 4 WeRead 0x0000000100c130d4 _ZN9spplcrash5async16gnu_ehptr_readerIyE4readEP23spplcrash_async_mobjectmlNS0_8DW_EH_PEEPyPm + 535828 5 WeRead 0x0000000100304914 WeRead + 2296084 6 WeRead 0x0000000100443de4 WeRead + 3603940 7 WeRead 0x0000000100442ba0 WeRead + 3599264 8 WeRead 0x000000010030475c WeRead + 2295644 9 UIKit 0x000000018d7e1494 <redacted> + 84 10 UIKit 0x000000018d2fd9a0 <redacted> + 96 11 UIKit 0x000000018d2fd920 <redacted> + 80
第二列是鏡像名,最后一列是這行代碼在運行時的偏移地址,對于同一個app和設備都是固定的,我們取每一行的這兩列來組成字符串再計算md5來標識某個堆棧,然后再判斷之前是否已經存在,如果存在就只上報函數名不上報堆棧。
下圖是我們某次內測的部分統計數據:
從統計數據來看,往往都有幾個斷言的人次特別多,其它比較少,我們目前只處理人次較多的問題。比如下面兩個斷言的人數不高,但次數很高,很可能是數據上出了問題,結合上傳的消息、堆棧以及查看具體源碼,很快就能知道是什么人、哪一本書哪一章節遇到問題,像下面第一個是緩存數據出了問題,會導致閱讀不了,第二個是遇到了沒有處理的css樣式,雖然它們都不會導致crash,但很可能會影響到閱讀體驗和產生其它問題。通過統計出這些Assert,我們能夠發現、定位并解決潛在的bug,提高代碼質量。
總結
隨著時間的推移,老代碼和框架始終會碰到bug和性能瓶頸,微信讀書針對現有的問題,開發出一些工具來輔助開發人員定位和解決問題,也取得一定的效果。目前這些工具還不能覆蓋所有問題,我們在編碼的同時會繼續追求更好的工具來輔助我們,減少我們埋坑的幾率和解決問題的時間。
來自:http://wereadteam.github.io/2016/12/12/Monitor/