背景

最近發(fā)現(xiàn)我們產(chǎn)品在打開廣告鏈接(Webview)時(shí)有一定概率會(huì)非常慢，白屏?xí)r間超過 10s，追查廣告的過程中遇到不少有意思的事情，感覺頗有收獲。在這里分享一下，主要想聊一聊追查 bug 時(shí)的那些方法論，當(dāng)然也不能太虛，還是要帶一點(diǎn)干貨，比如 WireShark 的使用。

Bug 復(fù)現(xiàn)

遇到 bug 后的***件事當(dāng)然是復(fù)現(xiàn)。經(jīng)過一番測(cè)試我發(fā)現(xiàn) bug 幾乎只會(huì)主要出現(xiàn)在 iPhone6 這種老舊機(jī)型上，而筆者的 7Plus 則基本沒有問題。4G 和 Wifi 下都有一定概率出現(xiàn)，Wifi 似乎更加頻繁。

其實(shí)有點(diǎn)經(jīng)驗(yàn)的開發(fā)者看到這里心里應(yīng)該有點(diǎn)譜了，這應(yīng)該不是客戶端的 bug，更可能是由于廣告主網(wǎng)頁(yè)質(zhì)量太低或者網(wǎng)絡(luò)環(huán)境不穩(wěn)定導(dǎo)致。但作為一個(gè)靠譜的程序員，怎么能把這種毫無根據(jù)的猜測(cè)向上級(jí)匯報(bào)呢?

關(guān)注點(diǎn)分離

我們知道加載網(wǎng)頁(yè)可以由兩部分時(shí)間組成，一個(gè)是本地的處理時(shí)間，另一個(gè)是網(wǎng)絡(luò)加載的時(shí)間。兩者的分水嶺應(yīng)該在 UIWebview 的 shouldStartLoadWithRequest 方法上。這個(gè)方法調(diào)用之前是本地處理耗時(shí)，調(diào)用之后是網(wǎng)絡(luò)加載的請(qǐng)求。所以我們可以把事情分成兩部分來看:

從 cell 接受點(diǎn)擊事件的 didSelectedRowAtIndexPath 起到 UIWebview 的 shouldStartLoadWithRequest 為止。

從 shouldStartLoadWithRequest 起到 UIWebview 的 webViewDidFinishLoad 為止。

由于 Bug 是偶現(xiàn)，所以不可能長(zhǎng)時(shí)間用 Xcode 調(diào)試，所以還要注意寫一個(gè)簡(jiǎn)單的工具，將每次的 Log 日志持久化存下來，保留每一步的函數(shù)調(diào)用、耗時(shí)、具體參數(shù)等。這樣一旦復(fù)現(xiàn)出來，可以連上電腦讀取手機(jī)中的日志。

本地處理

本地處理的耗時(shí)相對(duì)較短，但邏輯一點(diǎn)都不簡(jiǎn)單。在我個(gè)人看來，從展示 UITableview 到處理點(diǎn)擊事件的流程，足以反映出一個(gè)團(tuán)隊(duì)的技術(shù)實(shí)力。毫不夸張的說，能把這個(gè)小業(yè)務(wù)做到***的團(tuán)隊(duì)***，其中必然涉及到 MVC/MVVM 等架構(gòu)的選型設(shè)計(jì)與具體實(shí)現(xiàn)、網(wǎng)絡(luò)層與持久化層的封裝、項(xiàng)目模塊化的拆分等核心知識(shí)點(diǎn)。我會(huì)盡快抽空專門一些篇文章來聊聊這些，這里就不再贅述。

花了一番功夫整理好業(yè)務(wù)流程、做好統(tǒng)計(jì)以后還真有一些收獲。客戶端的邏輯是 pushViewController 動(dòng)畫執(zhí)行完后才發(fā)送請(qǐng)求，白白浪費(fèi)了大約 0.5s 的動(dòng)畫時(shí)間，這些時(shí)間原本可以用來加載網(wǎng)頁(yè)。

網(wǎng)絡(luò)請(qǐng)求

借助日志我還發(fā)現(xiàn)，本地處理雖然浪費(fèi)了時(shí)間，但這個(gè)時(shí)間相對(duì)穩(wěn)定，大約在 1s 左右。更大的耗時(shí)來自于網(wǎng)絡(luò)請(qǐng)求部分。一般情況下，打開網(wǎng)頁(yè)會(huì)有短暫的白屏?xí)r間，這段時(shí)間內(nèi)系統(tǒng)會(huì)加載 HTML 等資源并進(jìn)行渲染，同時(shí)界面上有菊花在轉(zhuǎn)動(dòng)。

白屏什么時(shí)候消失取決于系統(tǒng)什么時(shí)候加載完網(wǎng)頁(yè)，我們無法控制。但菊花消失的時(shí)間是已知的，我們的邏輯是寫在 webViewDidFinishLoad 中。這么做不一定準(zhǔn)確，因?yàn)榫W(wǎng)頁(yè)重定向時(shí)也會(huì)調(diào)用 webViewDidFinishLoad 方法導(dǎo)致客戶端誤以為已經(jīng)加載完成。更加準(zhǔn)確的做法可以參考: 如何準(zhǔn)確判斷 WebView 加載完成，當(dāng)然這也也僅僅是更準(zhǔn)確一些，就 UIWebview 而言，想準(zhǔn)確的判斷網(wǎng)絡(luò)是否加載完成幾乎是不可能的(感謝 @JackAlan 的實(shí)踐)。

所以說網(wǎng)絡(luò)加載還可以細(xì)分為兩部分，一個(gè)是純白屏?xí)r間，另一部分則是出現(xiàn)了網(wǎng)頁(yè)但還在轉(zhuǎn)動(dòng)菊花的時(shí)間。這是因?yàn)橐粋€(gè) Frame(可以是 HTML 也可以是 iFrame) 全部加載完成(包括 CSS/JS 等)后才會(huì)調(diào)用 webViewDidFinishLoad 方法，所以存在網(wǎng)頁(yè)已經(jīng)渲染但還在執(zhí)行 JS 請(qǐng)求的情況，反映在用戶端，就是能看到網(wǎng)頁(yè)但菊花還在轉(zhuǎn)動(dòng)。這種情況如果持續(xù)時(shí)間過久會(huì)導(dǎo)致用戶不耐煩，但相比于純粹的白屏?xí)r間來說更能被接受一些。

同時(shí)我們也可以確定，如果網(wǎng)頁(yè)已經(jīng)加載，但 JS 請(qǐng)求還在繼續(xù)，這就是廣告主的網(wǎng)頁(yè)質(zhì)量太差導(dǎo)致的。損失應(yīng)該由他們承擔(dān)，我們無能為力。而長(zhǎng)時(shí)間的白屏則是我們應(yīng)該重點(diǎn)考慮的問題。

小結(jié)

其實(shí)分析到這里已經(jīng)可以向領(lǐng)導(dǎo)匯報(bào)了。網(wǎng)絡(luò)加載的耗時(shí)一共是三段，***段是本地處理時(shí)間，存在性能浪費(fèi)但時(shí)間比較穩(wěn)定，第二段是網(wǎng)頁(yè)白屏?xí)r間，這段時(shí)間內(nèi)系統(tǒng)的 UIWebView 在請(qǐng)求資源并渲染，第三段是加載網(wǎng)頁(yè)后的菊花轉(zhuǎn)動(dòng)時(shí)間，一般耗時(shí)較少，我們也無法控制。

我們還知道 UIWebView 提供的 API 很少，從開始請(qǐng)求到網(wǎng)頁(yè)加載結(jié)束完全是黑盒模式，幾乎無從下手。但作為一名有追求，有理想，有抱負(fù)，有技術(shù)的四有程序員，怎么能輕言放棄呢?

WireShark

客戶端在調(diào)試網(wǎng)絡(luò)時(shí)最常用的工具要數(shù) Charles，但它只能調(diào)試 HTTP/HTTPS 請(qǐng)求，對(duì) TCP 層就無能為力了。要想了解 HTTP 請(qǐng)求過程中的細(xì)節(jié)，我們必須要使用威力更大(肯定也更復(fù)雜)的武器，也就是本文的主角 WireShark。

一般來說越牛X 的工具長(zhǎng)得就越丑，WireShark 也毫不例外的有著一副讓人懵逼的外表。 

不過不用太急，我們要用到的東西不多，頂部紅框里的藍(lán)色鯊魚標(biāo)志表示開始監(jiān)聽網(wǎng)絡(luò)數(shù)據(jù)，紅色按鈕一看也能猜出來是停止錄制。與 Charles 只監(jiān)聽 HTTP 請(qǐng)求不同的是，WireShark 可以調(diào)試到 IP 層甚至更細(xì)節(jié)，所以它的數(shù)據(jù)包也更多，幾秒鐘的時(shí)間就會(huì)被上千個(gè)請(qǐng)求淹沒，所以我建議用戶略微控制一下監(jiān)聽的時(shí)長(zhǎng)，或者我們可以在第二個(gè)紅框中輸入過濾條件來減少干擾，這個(gè)下文會(huì)詳細(xì)介紹。

WireShark 可以監(jiān)聽本機(jī)的網(wǎng)卡，也可以監(jiān)聽手機(jī)的網(wǎng)絡(luò)。使用 WireShark 調(diào)試真機(jī)時(shí)不用連接代理，只需要通過 USB 連接到電腦就行，否則就無法調(diào)試 4G 網(wǎng)絡(luò)了。我們可以用 rvictl -s 設(shè)備 UDID 命令來創(chuàng)建一個(gè)虛擬的網(wǎng)卡:

rvictl -s 902a6a449af014086dxxxxxx346490aaa0a8739

當(dāng)然，看手機(jī) UDID 還是挺麻煩的，作為一個(gè)懶人，怎么能不用命令行來完成呢?

instruments -s | awk '{print $NR}' | sed -n 3p | awk '{print substr($0,2,length($0)-2)}' | xargs rvictl -s

這樣只要連上手機(jī)，就可以直接獲取到 UDID 了。 

運(yùn)行命令后會(huì)看到成功創(chuàng)建 rvi0 虛擬網(wǎng)卡的提示，雙擊 rvi0 那一行即可。 

抓包界面

我們主要關(guān)注兩個(gè)內(nèi)容，上面的大紅框里面是數(shù)據(jù)流，包含了 TCP、DNS、ICMP、HTTP 等協(xié)議，顏色花花綠綠，絢麗多彩。一般來說黑色的內(nèi)容表示遇到錯(cuò)誤，需要重點(diǎn)關(guān)注，其他內(nèi)容則輔助理解。反復(fù)調(diào)試幾次以后也就能基本記住各種顏色對(duì)應(yīng)的含義了。

下面的小紅框里面主要是某一個(gè)包的數(shù)據(jù)詳解，會(huì)根據(jù)不同的協(xié)議層來劃分，比如我選中的 99 號(hào)包時(shí)一個(gè) TCP 包，可以很清楚的看到它的 IP 頭部、TCP 頭部和 TCP Payload。這些數(shù)據(jù)必要時(shí)可以做更詳細(xì)的分析，但一般也不用關(guān)注。 

一般來說一次請(qǐng)求的數(shù)據(jù)包會(huì)非常大，可能會(huì)有上千個(gè)，如何找到自己感興趣的請(qǐng)求呢，我們可以使用之前提到的過濾功能。WireShark 的過濾使用了一套自己定義的語法，不熟悉的話需要上網(wǎng)查一查或者借助自動(dòng)補(bǔ)全功能來“望文生義”。

由于是要查看 HTTP 請(qǐng)求的具體細(xì)節(jié)，我們先得找到請(qǐng)求的網(wǎng)址，然后利用 ping 命令得到它對(duì)應(yīng)的 IP 地址。這種做法一般沒問題，但也不排除有的域名會(huì)做一些優(yōu)化，比如不同的 IP 請(qǐng)求 DNS 解析時(shí)返回不同的 IP 地址來保證***速度。也就是說手機(jī)上 DNS 解析的結(jié)果并不總是和電腦上的解析結(jié)果一致。這種情況下我們可以通過查看 DNS 數(shù)據(jù)包來確定。 

比如從圖中可以看到 res.wx.qq.com 這個(gè)域名解析出了一大堆 IP 地址，而真正使用的僅有前兩個(gè)。

解析出地址后，我們就可以做簡(jiǎn)單的過濾了，輸入ip.addr == 220.194.203.68: 

這樣就只顯示和 220.194.203.68 主機(jī)之間的通信了。注意紅框中的 SourcePort，這是客戶端端口。我們知道 HTTP 支持并發(fā)請(qǐng)求，不同的并發(fā)請(qǐng)求肯定是占用不同的端口。所以在圖中看到的上下兩個(gè)數(shù)據(jù)包，并非一定是請(qǐng)求與響應(yīng)的關(guān)系，他們可能屬于兩個(gè)不同的端口，彼此之間毫無關(guān)系，只是恰好在時(shí)間上最接近而已。

如果只想顯示某個(gè)端口的數(shù)據(jù)，可以使用:ip.addr == 220.194.203.68 and tcp.dstport == 58854。

如果只想看 HTTP 協(xié)議的 GET 請(qǐng)求與響應(yīng)，可以使用 ip.addr == 220.194.203.68 and (http.request.method == "GET" || http.response.code == 200) 來過濾。

如果想看丟包方面的數(shù)據(jù)，可以用 ip.addr == 220.194.203.68 and (tcp.analysis.fast_retransmission || tcp.analysis.retransmission)

以上是筆者在調(diào)試過程中用到比較多的命令，僅供參考。有興趣的讀者可以自行抓包實(shí)驗(yàn)，就不挨個(gè)貼圖了。

Case1: DNS解析

經(jīng)過多次抓包后我開始分析那些長(zhǎng)時(shí)間白屏的網(wǎng)頁(yè)對(duì)應(yīng)的數(shù)據(jù)包，果然發(fā)現(xiàn)不少問題，比如這里: 

可以很明顯的看到在一大串黑色錯(cuò)誤信息，但如果你去調(diào)試這些數(shù)據(jù)包，那么就掉進(jìn)陷阱了。DNS 是基于 UDP 的協(xié)議，不會(huì)有 TCP 重傳，所以這些黑色的數(shù)據(jù)包必定是之前的丟包重傳，不用關(guān)心。如果只看藍(lán)色的 DNS 請(qǐng)求，就會(huì)發(fā)現(xiàn)連續(xù)發(fā)送了幾個(gè)請(qǐng)求但都沒有響應(yīng)，直到第 12s 才得到解析后的IP 地址。

從 DNS 請(qǐng)求的接收方的地址以 172.24 開頭可以看出，這是內(nèi)網(wǎng) DNS 服務(wù)器，不知道為什么卡了很久。

Case2: 握手響應(yīng)延遲

下圖是一次典型的 TCP 握手時(shí)的場(chǎng)景。同時(shí)也可以看到***張圖中的 SYN 握手包發(fā)出后，過了一秒鐘才接受到 ACK。當(dāng)然了，原因也不清楚，只能解釋為網(wǎng)絡(luò)抖動(dòng)。 

隨后我又在 4G 網(wǎng)絡(luò)下抓了一次包: 

這次事情就更離譜了，第二秒發(fā)出的 SYN 握手包反復(fù)丟失(也有可能是服務(wù)端沒有響應(yīng)、或者是 ACK 丟失)，總之客戶端不斷重傳 SYN 包。

更有意思的是，觀察 TSval，它表示包發(fā)出時(shí)的時(shí)間戳。我們觀察這幾個(gè)值會(huì)發(fā)現(xiàn)，前幾次的間隔時(shí)間是 1s，后來變成了 2s，4s 和 8s。這不禁讓我想起了 RTO 的概念。

我們知道 RTT 表示的是網(wǎng)絡(luò)請(qǐng)求從發(fā)起到接收響應(yīng)的時(shí)間，它是一個(gè)隨著網(wǎng)絡(luò)環(huán)境而動(dòng)態(tài)改變的值。TCP 有窗口的概念，對(duì)于窗口的***個(gè)數(shù)據(jù)包，如果它無法發(fā)送，窗口就不能向后滑動(dòng)?？蛻舳艘越邮盏?ACK 作為數(shù)據(jù)包成功發(fā)送的標(biāo)志，那么如果 ACK 收不到呢?客戶端當(dāng)然不會(huì)一直等下去，它會(huì)設(shè)置一個(gè)超時(shí)時(shí)間，一旦超過這個(gè)時(shí)間就認(rèn)為數(shù)據(jù)包丟失，從而重傳。

這個(gè)超時(shí)時(shí)間就被稱為 RTO，顯然它必須略大于 RTT，否則就會(huì)誤報(bào)數(shù)據(jù)包丟失。但也不能過大，否則會(huì)浪費(fèi)時(shí)間。因此合理的 RTO 必須跟隨 RTT 動(dòng)態(tài)調(diào)整，始終保證大于 RTT 但也不至于太大。觀察上面的截圖可以發(fā)現(xiàn)，某些情況下 RTT 會(huì)非常小，小到只有幾毫秒。如果 RTO 也設(shè)置為幾毫秒就會(huì)顯得不太合理，這會(huì)加大客戶端和沿途各路由器的壓力。因此 RTO 還會(huì)設(shè)置下限，不同的操作系統(tǒng)可能有不同的實(shí)現(xiàn)，比如 Linux 上是 200ms。同時(shí)，RTO 也會(huì)設(shè)置上限，具體的算法可以參考這篇文章 和這篇文章。

需要注意的是，RTO 隨著 RTT 動(dòng)態(tài)變化，但如果達(dá)到了 RTO 導(dǎo)致了超時(shí)重傳，以后的 RTO 就不再隨著 RTT 變化了(此時(shí)的 RTT 無法計(jì)算)，會(huì)指數(shù)增長(zhǎng)。也就是上面截圖中的間隔時(shí)間從 2s 變成 4s 再變成 8s 的原因。

同樣的，我們發(fā)現(xiàn)了握手花費(fèi)了 20s 這一現(xiàn)象，但無法給出準(zhǔn)確原因，只能解釋為網(wǎng)絡(luò)抖動(dòng)。

總結(jié)

通過 TCP 層面的抓包，我們不僅僅學(xué)習(xí)了 WireShark 的使用，也復(fù)習(xí)了 TCP 協(xié)議的相關(guān)知識(shí)，對(duì)問題的分析也更加深入。從最初的網(wǎng)絡(luò)問題開始細(xì)化挖掘，得出了白屏?xí)r間過長(zhǎng)、網(wǎng)頁(yè)加載太慢的結(jié)論，最終又具體的計(jì)算出了有多少個(gè) HTTP 請(qǐng)求，DNS 解析、TCP 握手、TCP 數(shù)據(jù)傳輸?shù)雀鱾€(gè)階段的耗時(shí)。由此看來，網(wǎng)頁(yè)加載慢的罪魁禍?zhǔn)撞⒎菑V告主網(wǎng)頁(yè)的質(zhì)量問題，而是網(wǎng)絡(luò)的不穩(wěn)定問題。雖然最終也沒有得到有效的解決方案，但至少明確了問題的發(fā)生原因，給出了令人信服的解釋。