本文前戲較多，務實的同學可以直接跳到結論。
由「鋼的琴」網友腦洞大開延伸出了吉的他二的胡琵的琶，以及后來許嵩的「蘇格拉沒有底」，是否可以再拓展一下，得到哥本不愛吃哈根，哈根愛達斯等劇情亂入的關系。
上面跟本文要討論的主題有什么關系？
沒關系。
緣起
有用戶反饋內部MIS系統慢，頁面加載耗時長。前端同學們開組會提及此事，如何解決慢的問題。
最致命的是：偶發！你不能準確知道它抽風的時間點，無法在想要追查問題的時候必現它。
這只是一方面，另外，慢的可能實在太多了，那么問題來了，是前端導致的還是后端的問題？
對慢的定義也有待商榷，多久算慢？如果這個頁面加載大量數據耗時增加那我認為這是正常的。但這個時限超過了一個合理的自然值，就變得不那么正常了，比如四五十秒，一分多鐘。
最奇葩的是，如此久的耗時居然不會報超時錯誤，而是拿到正確返回后將頁面呈現了出來！
可能的原因
初步猜測
初步的猜測可能是后端遲遲未返回造成瀏覽器處于等待狀態。這個猜測是很合乎邏輯的，至少能夠很合理地解釋Chrome Dev Tool 網絡面板中我們看到的狀態pending。
但我們不能停留在猜測階段，要用事實說話，數據才不會騙人。這也正是本文將要展開的。
下面是另外一些被提出來的可能性。
Angular
Angular首當其沖。為什么，因為這個問題出現在后臺MIS系統中，且這些系統多用Angular開發。
Angular ：怪我咯。
因為問題多出現在基于Angular的MIS系統中，并且Angular的性能一直是被詬病的，所以聽到不少的聲音將矛頭指向Angular。這似乎沒什么好庇護的。Angular在整個項目中的前端部分扮演了很重的角色。樹大招風，理所當然。
這讓我想起初次接觸到這個問題時，那是在七月份，芙蓉的愛馬仕平臺用戶反饋了慢的問題，報到前端，順便看了下，一看Pending狀態，覺得是后端未返回。只是情深緣淺當時也沒有深入，同時洪堂大神負責去追查了。當時那個系統，很負責地說，沒有用Angular。
所以這里可以為Angular正身，將其排除。
內部封裝的commonResource庫
內部對Angular原生的resource進行了封裝，做了些數據的轉換處理。既然上面Angular都被正身了，那么這里的懷疑也是站不住腳的。
Chrome插件
經查，網上好多呼聲有說是Adblock等與網絡有關的Chrome插件。可我不使用它已經很多年，那玩意兒太重，后來找到了算法更高級體量更輕便的µBlock。關鍵是后者也在我使用一段時間后放棄了，因為個人覺悟提高了，免費內容是需要廣告支撐的，如果你不希望付費變成強制的話。所以現在一直是處于未開這類插件的狀態。那么在未開廣告屏蔽插件的情況下重現了問題，可以排除這類插件的影響了。
關于插件，此刻我的Chrome里唯一還會接管Chrome網絡的便是代理插件SwitchSharp, 升級之后這貨叫Switchy哦賣喝（與時俱進的我當然使用的是后者）。
Chrome獨家？
因為內部MIS只兼容了Chrome開發，所以不會有在除了Chrome之外的瀏覽器上使用的場景，并且其他瀏覽器上面追查問題也是很痛苦的事情。這里僅在火狐里進行了少量嘗試，未復現。同時接到反饋，Safari里也未復現。但也不能肯定就只有Chrome存在問題。似乎這個對于問題的解決還不那么重要，所以先不管。
殺毒軟件
后面會看到，在追查錯誤號ERR_CONNECTION_RESET時引出了殺毒軟件可能會導致Chrome工作不正常的情況，但這個可能也在稍后被排除人。
并且，我廠使用Mac的同學并沒有安裝殺軟，依然是可以復現的。
重現
第一件事情便是重現。雖然是偶發，為了盡可能保存現場，還是想要手動將它刷出來。天不滅我，經過良久嘗試，該問題被復現。于是各種截圖，保存請求數據。這個時候還沒有開啟chrome://net-internals/#events頁面來捕獲事件日志。
為以后引用方便，這里留下版本信息：
OS： Windows 7 Ultimate
Chrome：Version 39.0.2171.95 m
這是請求Pending時的請求信息：
這是請求成功返回后：
可以看到Stalled了1分多鐘。神奇的是竟然不報超時錯誤而是成功返回了。
同時保存了請求頭，響應頭，還將本次問題請求保存成了CURL等。現場已經留下，感覺Bug不會存活太久了。
接下來就是對比正常請求跟這次異常請求的不同，一輪比較下來，未發現多少異常。
常態與變態的對比
請求頭對比：
請求頭的對比已丟失，但除了時間外，其余無差別。
響應頭對比：
返回結果對比：
上面的對比意義不大，但還是要做的，萬一發現有價值的情報了呢。
一次失敗的嘗試
解決問題時，習慣性地看有沒有人已經碰過到類似問題，這樣做的好處很明顯：
如果有，站在巨人的肩上輕松地牛逼著；
如果沒有，這是個機會。
于是信心滿滿地出發了，因為根據一條互聯網準則，70%的問題已經有人解決過了，那些沒有被解決的要么是現有技術達不到，要么是未被人發現。所以能夠搜索出問題答案的概率還是蠻大的。
經過曠日持久的搜索，有價值的參考寥寥無幾。可能是問題本身太過奇葩，遇到的人太少；也有可能問題過于晦澀，無法表述；抑或我搜索的關鍵詞不夠精準。
倒也不是說一個都沒找到，但一般涉及網絡日志的情況就無人問津了，無人問津了！
比如這個，一年多前被人問的，現在還沒有一個回答。
還比如這個
Chrome stalls when making multiple requests to same resource?
是后來作為參考的，也是無人問津了……
甚至自己也去問了一個，依然無人問津了……
神秘的CACHE LOCK
上面提到，Stackoverflow上找到一個問題，跟現在需要解決一有些類似點：
- 偶發，并不是必然出現的。這里我們的問題也是偶發，很難復現，需要反復刷。
- 也是請求被
Pending了很久，從請求的時間線來看，體現在Stalled上。
這一刻，有一種感覺大概是這樣的：
偉大的意大利的左后衛！他繼承了意大利的光榮的傳統。法切蒂、卡布里尼、馬爾蒂尼在這一刻靈魂附體！格羅索一個人他代表了意大利足球悠久的歷史和傳統，在這一刻他不是一個人在戰斗，他不是一個人！
突然看到了希望。該提問到沒有給出什么建設性的意見，但它后面的追加編輯卻給出了答案。過程是查看Chrome的網絡日志，在事件里面發現有一個超時錯誤：
t=33627 [st= 5] HTTP_CACHE_ADD_TO_ENTRY [dt=20001]
--> net_error = -409 (ERR_CACHE_LOCK_TIMEOUT)
耗時20秒之久！而且寫得非常明顯是ERR_CACHE_LOCK_TIMEOUT。根據提問者貼出來的鏈接，了解到Chrome有一個緩存鎖的機制。
具體源于一個今年6月分實現的一個補丁，加入了這么個機制，而這個機制的引入又源于2010年的一個issue。具體信息可以通過這個這里查看，下面引用如下。
Basically here is the situation:
The site author has a long-lived XHR being used to stream a slow response from the server. This XHR response is cachable (it is just really slow). They kick off the XHR asynchronously, and as data slowly arrives on it, update the progressive load of the webpage. Cool.
Now what happens if you try to load this page in multiple tabs of Chrome is:
The first page starts to load just fine, but the second one does nothing.
What has happened, is the background XHR of the first page load has acquired an exclusive lock to the cache entry, and the background XHR of the second page is stalled at "Waiting for cache..." trying to get a reader access to the cache entry.
Since the first request can takes minutes, this is a problem.
eroman 同學指出了這么一個事實：
瀏覽器對一個資源發起請求前，會先檢查本地緩存，此時這個請求對該資源對應的緩存的讀寫是獨占的。那么問題來了，試想一下，當我新開一個標簽嘗試訪問同一個資源的時候，這次請求也會去讀取這個緩存，假設之前那次請求很慢，耗時很久，那么后來這次請求因為無法獲取對該緩存的操作權限就一直處于等待狀態。這樣很不科學。于是有人建議優化一下。也就是上面所描述的那樣。
隨著問題的提出，還出了兩種可能的實現方案。
(a) [Flexible but complicated] Allow cache readers WHILE writing is in progress. This way the first request could still have exclusive access to the cache entry, but the second request could be streamed the results as they get written to the cache entry. The end result is the second page load would mirror the progress of the first one.
(a) [Naive but simpler] Have a timeout on how long we will block readers waiting for a cache entry before giving up and bypassing the cache.
我猜上面第二個(a)應該是(b)。簡單說第一種優化方案更加復雜但科學。之前的請求對緩存仍然是獨占的，但隨著前一次請求不斷對緩存進行更新，可以把已經更新的部分拿給后面的請求讀取，這樣就不會完全阻塞后面的請求了。
第二種方案則更加簡單暴力。給后來的請求設定一個讀取緩存超時的時限，如果超過了這個時限，我認為緩存不可用或者本地沒有緩存，忽略這一步直接發請求。
于是Chromium的開發者們選擇了后者簡單的實現。也就是Issue 345643003: Http cache: Implement a timeout for the cache lock 這個提交里的實現。
這個提交的描述如下：
The cache has a single writer / multiple reader lock to avoid downloading the same resource n times. However, it is possible to block many tabs on the same resource, for instance behind an auth dialog.
This CL implements a 20 seconds timeout so that the scenario described in the bug results in multiple authentication dialogs (one per blocked tab) so the user can know what to do. It will also help with other cases when the single writer blocks for a long time.
The timeout is somewhat arbitrary but it should allow medium size resources to be downloaded before starting another request for the same item. The general solution of detecting progress and allow readers to start before the writer finishes should be implemented on another CL.
于是就產生了上面題主遇到的情況。
所以他的解決方法就很明朗了，對請求加個時間戳讓其變得唯一，或者服務器響應頭設置為無緩存。Both will work!
那么我們的問題也會是這樣的么？我幻想由于某種未知的原因造成之前的請求不正常（雖然網絡面板里沒有數據證明這樣的阻塞請求在問題請求之前存在），然后我們的MIS里打開頁面時讀取不到緩存，卡了，一會兒緩存好了，正常了，于是在等待了幾十秒后請求成功發出去了。
似乎不太可能。因為恰好內部MIS系統的響應頭里已經加了緩存控制了 Cache-Control: no-cache。
以下是一次問題請求的響應頭：
HTTP/1.1 200 OK
Date: Wed, 31 Dec 2014 11:47:21 GMT
Content-Type: application/json; charset=UTF-8
Transfer-Encoding: chunked
Connection: keep-alive
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Pragma: no-cache
Cache-Control: no-cache
tracecode: 28410188240979065866123119
tracecode: 28410188240506537994123119
Server: Apache
并且開多個標簽也是無法進行有效重現的。
因此可以排除緩存的干擾。那么似乎這里的緩存鎖并不是導致問題的原因，只能另尋他路。不得不說，高興過后有點失望。
八卦時間
可喜的是，在細細口味了上面緩存機制引入的過程后，真是耐人尋味。這里不妨八卦一下。相信你也注意到了，上面提到，該緩存問題的提出是在2010年，確切地說是Jun 8, 2010。是的，2010年6月8日由eroman 同學提出。但最后針對該問題進行修復的代碼提交卻是在今年6月份，2014年6月24日，提交時間擺在那里我會亂說？
于是好奇為什么會拖了這么久，遂跟了一下該問題下面的回復看看發生了什么。簡直驚呆了。
同月14號，有了首次對這個問題的回復，那是將該問題指派給了rvargas同學。
一個月過去了，也就是7月15號，rvargas同學指出了與該問題關聯的另外一個issue「issue 6697」
接下來是8月5日，rvargas同學為該問題貼上了標簽
-Mstone-7 Mstone-8，表明將會在里程碑7或者8里面進行修復。但在后面的10月7日，這個日程又被推到了-Mstone-8 Mstone-9。再接下來11月5日，有人表示以目前的速度及bug數量，還沒有時間來修復它，重點在處理優先級為
p1的問題上。于是此問題又成功被順延了，來到-mstone-9 Mstone-10，同時優級降為p2。Chromium人手也不夠啊，看來。時間來到12月9日，因為優先級為
p2的issue如果沒有被標為開始狀態的話又自動推到下一個里程碑了，于是順利來到-Mstone-10 MovedFrom-10 Mstone-11。次年2月來到-Mstone-11 Mstone-12。完成了一次跨年！
…………
上面省略N步。如此反復，最后一次被推到了
-Mstone-16，那是在2011年10月12日。時間一晃來到2013年，這一年很平靜，前面的幾個月都沒有人對此問題進行回復。直到11月27日，有人看不下去了，評論道：
This bug has been pushed to the next mstone forever...and is blocking more bugs (e.g https://code.google.com/p/chromium/issues/detail?id=31014)and use-cases same video in 2 tags on one page, and adaptive bit rate html5 video streaming whenever that will kick in. Any chance this will be prioritized?
由于這個bug的無限后延也阻塞了另外一些同類問題，看來是時候解決了。這不，最初的owner 當天就進行了回復：
ecently there was someone looking at giving it another try... I'd have to see if there was any progress there.
If not, I may try to fix it in Q1.
最后一句亮瞎。敢情這之前owner就沒有想過要去真正解決似的，因為有其他人在看這個問題了，所以就沒管了，如果Q1還沒人解決的話，我會出手的！嗯，就是這個意思。
…………
最后，也就是上文提到的，2014年6月，還是rvargas同學對這個問題進行了修復，實現了對緩存讀取20秒超時的控制。
該問題就是這樣從2010來到2014的。我懷疑Chrome是如何成為版本帝的。
階段總結
僅有的希望到此似乎都沒有了。不過前面的努力也不是沒有作何收獲，至少我得到了以下有價值的信息：
- 谷歌的神壇光環不再那么耀眼，他們的產品也是有Bug的
- Chrome 處理issue的效率，當然不排除這種大型項目bug數量跟人力完全不匹配的情況
- 受上面Stackoverflow問題的啟發，接下來我將重點轉移到了針對出問題請求的日志分析上，并且取得了突破
開始新的征程
雖然上面的努力沒能定位到問題，但作為這次對解決這次問題的嘗試，還是將它記錄了下來，估且稱作「舊的回憶」吧。
下面開始「新的征程」。
再次重現
這次受到上面的啟發，開啟chrome://net-internals/#events頁面來捕獲事件日志。看是否有錯誤或異常發生。
再次經過曠日持久的機械操作，重現了！這次，日志在手，天下我有。感覺Bug不會存活多久了。
Chrome Dev Tools 網絡面板截圖：
由上面的截圖看到，本次出問題的請求總耗時42.74秒。
問題請求的時間線信息截圖：
可以預見，通過捕獲的日志完全可以看到Stalled那么久都發生了些什么鬼。
話不多說，切換到事件捕獲頁面，定位到出問題的請求，查看其詳情。同時將該日志導出，永久保存！作為紀念，也方便以后再次導入查看。有興趣的同學可以訪問下方下載后進行導入，就可以清晰地查看到現場了，就好像你親歷了整個犯罪現場一樣。
日志還原
- 在Chrome新開一個標簽輸入
chrome://net-internals/#events - 切換到
Import，選擇剛才下載的JSON文件進行導入 切換到
Events，定位到http://qa.tieba.baidu.com/release/getReleaseHistory?projectId=fum1.0.593這個請求
此刻右邊出現的便是該問題請求的詳細日志。
日志解讀
下面不妨把日志文件貼出來先：
193486: URL_REQUEST
http://qa.tieba.baidu.com/release/getReleaseHistory?projectId=fum1.0.593
Start Time: 2015-01-02 17:51:05.323
t= 1 [st= 0] +REQUEST_ALIVE [dt=42741]
t= 1 [st= 0] URL_REQUEST_DELEGATE [dt=0]
t= 1 [st= 0] +URL_REQUEST_START_JOB [dt=42740]
--> load_flags = 339804160 (BYPASS_DATA_REDUCTION_PROXY | MAYBE_USER_GESTURE | REPORT_RAW_HEADERS | VERIFY_EV_CERT)
--> method = "GET"
--> priority = "LOW"
--> url = "http://qa.tieba.baidu.com/release/getReleaseHistory?projectId=fum1.0.593"
t= 2 [st= 1] URL_REQUEST_DELEGATE [dt=0]
t= 2 [st= 1] HTTP_CACHE_GET_BACKEND [dt=0]
t= 2 [st= 1] HTTP_CACHE_OPEN_ENTRY [dt=0]
t= 2 [st= 1] HTTP_CACHE_ADD_TO_ENTRY [dt=0]
t= 2 [st= 1] HTTP_CACHE_READ_INFO [dt=0]
t= 2 [st= 1] URL_REQUEST_DELEGATE [dt=0]
t= 2 [st= 1] +HTTP_STREAM_REQUEST [dt=2]
t= 4 [st= 3] HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 193488 (HTTP_STREAM_JOB)
t= 4 [st= 3] -HTTP_STREAM_REQUEST
t= 4 [st= 3] +HTTP_TRANSACTION_SEND_REQUEST [dt=0]
t= 4 [st= 3] HTTP_TRANSACTION_SEND_REQUEST_HEADERS
--> GET /release/getReleaseHistory?projectId=fum1.0.593 HTTP/1.1
Host: qa.tieba.baidu.com
Connection: keep-alive
Accept: application/json, text/plain, */*
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.95 Safari/537.36
Referer: http://qa.tieba.baidu.com/project/
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-US,en;q=0.8
Cookie: [268 bytes were stripped]
t= 4 [st= 3] -HTTP_TRANSACTION_SEND_REQUEST
t= 4 [st= 3] +HTTP_TRANSACTION_READ_HEADERS [dt=21301]
t= 4 [st= 3] HTTP_STREAM_PARSER_READ_HEADERS [dt=21301]
--> net_error = -101 (ERR_CONNECTION_RESET)
t=21305 [st=21304] HTTP_TRANSACTION_RESTART_AFTER_ERROR
--> net_error = -101 (ERR_CONNECTION_RESET)
t=21305 [st=21304] -HTTP_TRANSACTION_READ_HEADERS
t=21305 [st=21304] +HTTP_STREAM_REQUEST [dt=3]
t=21307 [st=21306] HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 193494 (HTTP_STREAM_JOB)
t=21308 [st=21307] -HTTP_STREAM_REQUEST
t=21308 [st=21307] +HTTP_TRANSACTION_SEND_REQUEST [dt=3]
t=21308 [st=21307] HTTP_TRANSACTION_SEND_REQUEST_HEADERS
--> GET /release/getReleaseHistory?projectId=fum1.0.593 HTTP/1.1
Host: qa.tieba.baidu.com
Connection: keep-alive
Accept: application/json, text/plain, */*
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.95 Safari/537.36
Referer: http://qa.tieba.baidu.com/project/
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-US,en;q=0.8
Cookie: [268 bytes were stripped]
t=21311 [st=21310] -HTTP_TRANSACTION_SEND_REQUEST
t=21311 [st=21310] +HTTP_TRANSACTION_READ_HEADERS [dt=21304]
t=21311 [st=21310] HTTP_STREAM_PARSER_READ_HEADERS [dt=21304]
--> net_error = -101 (ERR_CONNECTION_RESET)
t=42615 [st=42614] HTTP_TRANSACTION_RESTART_AFTER_ERROR
--> net_error = -101 (ERR_CONNECTION_RESET)
t=42615 [st=42614] -HTTP_TRANSACTION_READ_HEADERS
t=42615 [st=42614] +HTTP_STREAM_REQUEST [dt=12]
t=42627 [st=42626] HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 193498 (HTTP_STREAM_JOB)
t=42627 [st=42626] -HTTP_STREAM_REQUEST
t=42627 [st=42626] +HTTP_TRANSACTION_SEND_REQUEST [dt=2]
t=42627 [st=42626] HTTP_TRANSACTION_SEND_REQUEST_HEADERS
--> GET /release/getReleaseHistory?projectId=fum1.0.593 HTTP/1.1
Host: qa.tieba.baidu.com
Connection: keep-alive
Accept: application/json, text/plain, */*
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.95 Safari/537.36
Referer: http://qa.tieba.baidu.com/project/
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-US,en;q=0.8
Cookie: [268 bytes were stripped]
t=42629 [st=42628] -HTTP_TRANSACTION_SEND_REQUEST
t=42629 [st=42628] +HTTP_TRANSACTION_READ_HEADERS [dt=112]
t=42629 [st=42628] HTTP_STREAM_PARSER_READ_HEADERS [dt=112]
t=42741 [st=42740] HTTP_TRANSACTION_READ_RESPONSE_HEADERS
--> HTTP/1.1 200 OK
Date: Fri, 02 Jan 2015 09:51:48 GMT
Content-Type: application/json; charset=UTF-8
Transfer-Encoding: chunked
Connection: keep-alive
Cache-Control: no-cache
tracecode: 31079600320335034634010217
tracecode: 31079600320537995786010217
Server: Apache
t=42741 [st=42740] -HTTP_TRANSACTION_READ_HEADERS
t=42741 [st=42740] HTTP_CACHE_WRITE_INFO [dt=0]
t=42741 [st=42740] HTTP_CACHE_WRITE_DATA [dt=0]
t=42741 [st=42740] HTTP_CACHE_WRITE_INFO [dt=0]
t=42741 [st=42740] URL_REQUEST_DELEGATE [dt=0]
t=42741 [st=42740] -URL_REQUEST_START_JOB
t=42741 [st=42740] URL_REQUEST_DELEGATE [dt=0]
t=42741 [st=42740] HTTP_TRANSACTION_READ_BODY [dt=0]
t=42741 [st=42740] HTTP_CACHE_WRITE_DATA [dt=0]
t=42741 [st=42740] HTTP_TRANSACTION_READ_BODY [dt=0]
t=42741 [st=42740] HTTP_CACHE_WRITE_DATA [dt=0]
t=42742 [st=42741] -REQUEST_ALIVE首先，日志顯示的總耗時與上面網絡面板截圖的總耗時是吻合的，都是42.74秒，說明我們定位正確。
以下時間均以毫秒計
日志第一列為時間線，自請求發起時算。
第二列為每步操作所逝去的時間，時間差的概念，與第三列里面的dt不同，它會積累前面的耗時。
第三列為具體的事件，以及相應事件的耗時dt，此耗時為絕對耗時。
+號對應事件開始，-號對應事件結束，也就是說他們必然成對出現。住里是展開后更加詳細的子事件。直到不能再細分。
如果說一開始接觸到這個日志時手足無措的話，我們來看一下正常情況下的日志是怎樣的，有對比才有發現。
以下隨便摘取一次正常請求的日志，如下：
384462: URL_REQUEST
http://qa.tieba.baidu.com/release/getReleaseHistory?projectId=fum1.0.593
Start Time: 2015-01-03 20:23:54.698
t=1556 [st= 0] +REQUEST_ALIVE [dt=172]
t=1556 [st= 0] URL_REQUEST_DELEGATE [dt=0]
t=1556 [st= 0] +URL_REQUEST_START_JOB [dt=171]
--> load_flags = 335609856 (BYPASS_DATA_REDUCTION_PROXY | MAYBE_USER_GESTURE | VERIFY_EV_CERT)
--> method = "GET"
--> priority = "LOW"
--> url = "http://qa.tieba.baidu.com/release/getReleaseHistory?projectId=fum1.0.593"
t=1557 [st= 1] +URL_REQUEST_DELEGATE [dt=4]
t=1557 [st= 1] DELEGATE_INFO [dt=4]
--> delegate_info = "extension Tampermonkey"
t=1561 [st= 5] -URL_REQUEST_DELEGATE
t=1561 [st= 5] HTTP_CACHE_GET_BACKEND [dt=0]
t=1561 [st= 5] HTTP_CACHE_OPEN_ENTRY [dt=1]
--> net_error = -2 (ERR_FAILED)
t=1562 [st= 6] HTTP_CACHE_CREATE_ENTRY [dt=0]
t=1562 [st= 6] HTTP_CACHE_ADD_TO_ENTRY [dt=0]
t=1562 [st= 6] URL_REQUEST_DELEGATE [dt=0]
t=1562 [st= 6] +HTTP_STREAM_REQUEST [dt=2]
t=1564 [st= 8] HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 384467 (HTTP_STREAM_JOB)
t=1564 [st= 8] -HTTP_STREAM_REQUEST
t=1564 [st= 8] +HTTP_TRANSACTION_SEND_REQUEST [dt=1]
t=1564 [st= 8] HTTP_TRANSACTION_SEND_REQUEST_HEADERS
--> GET /release/getReleaseHistory?projectId=fum1.0.593 HTTP/1.1
Host: qa.tieba.baidu.com
Connection: keep-alive
Accept: application/json, text/plain, */*
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.95 Safari/537.36
Referer: http://qa.tieba.baidu.com/project/
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-US,en;q=0.8
Cookie: [2642 bytes were stripped]
t=1565 [st= 9] -HTTP_TRANSACTION_SEND_REQUEST
t=1565 [st= 9] +HTTP_TRANSACTION_READ_HEADERS [dt=161]
t=1565 [st= 9] HTTP_STREAM_PARSER_READ_HEADERS [dt=160]
t=1725 [st=169] HTTP_TRANSACTION_READ_RESPONSE_HEADERS
--> HTTP/1.1 200 OK
Date: Sat, 03 Jan 2015 12:23:54 GMT
Content-Type: application/json; charset=UTF-8
Transfer-Encoding: chunked
Connection: keep-alive
Cache-Control: no-cache
tracecode: 14346880480340800522010320
tracecode: 14346880480253893130010320
Server: Apache
t=1726 [st=170] -HTTP_TRANSACTION_READ_HEADERS
t=1726 [st=170] HTTP_CACHE_WRITE_INFO [dt=0]
t=1726 [st=170] HTTP_CACHE_WRITE_DATA [dt=0]
t=1726 [st=170] HTTP_CACHE_WRITE_INFO [dt=0]
t=1726 [st=170] +URL_REQUEST_DELEGATE [dt=1]
t=1726 [st=170] DELEGATE_INFO [dt=1]
--> delegate_info = "extension Tampermonkey"
t=1727 [st=171] -URL_REQUEST_DELEGATE
t=1727 [st=171] -URL_REQUEST_START_JOB
t=1727 [st=171] URL_REQUEST_DELEGATE [dt=0]
t=1727 [st=171] HTTP_TRANSACTION_READ_BODY [dt=0]
t=1727 [st=171] HTTP_CACHE_WRITE_DATA [dt=1]
t=1728 [st=172] HTTP_TRANSACTION_READ_BODY [dt=0]
t=1728 [st=172] HTTP_CACHE_WRITE_DATA [dt=0]
t=1728 [st=172] -REQUEST_ALIVE針對上面正常的請求，我們主要關注兩部分，如下面的截圖：
- 發送請求頭
+HTTP_TRANSACTION_SEND_REQUEST [dt=1] - 讀取響應頭
+HTTP_TRANSACTION_READ_HEADERS [dt=161]
這是正常的情況下，沒有什么問題。并且日志里可以清晰地看到發送的請求頭是什么，然后解析出來的響應頭是什么。這跟在網絡面板看到的是一致的。
再回到出問題的請求日志上來，同樣我們只關注這兩部分。如下面的截圖：
與正常相比，最后一次發送請求和讀取響應頭無異常，時間就多在了前面還有再次發送和請求的過程，細看時間都花在了以下兩個事件中：
HTTP_STREAM_PARSER_READ_HEADERS [dt=21301]HTTP_STREAM_PARSER_READ_HEADERS [dt=21304]
該事件的名稱已經自我解讀，意思是解析讀取的響應頭。但問題是緊接著下面報錯了，
--> net_error = -101 (ERR_CONNECTION_RESET)讀取響應頭時發生了鏈接重置的錯誤，有理由認為本次鏈接是不成功的，沒拿到正確的響應頭，于是解析不成功。時間都花在了這里，足足21秒之久，兩個21秒造就了上面看到的Stalled了42秒之久。
問題似乎已經很明朗了。鏈接被重置。
在第三次嘗試的時候正常了，于是正確返回，我們才看到了被解析的響應頭被展示在了下面。也就是說在出問題的時候要么響應頭未拿到，要么響應頭非法導致解析不成功。而原因就是鏈接被重置。
那么接下來的工作就是對ERR_CONNECTION_RESET這個錯誤的追查了。
官方關于 ERR_CONNECTION_RESET 錯誤的解釋
未找到官方相應的資料，Chrome官網上唯一關于此錯誤的描述是在安裝Chrome時出現Error 101。我估計文檔的撰寫人員沒想到誰會這么蛋疼想要看這些生澀的東西，除了開發者。既然你都是開發者了，那為什么不去看Chromium的源碼。
好吧，唯一的途徑似乎只能從源碼中尋找了。作為只精JS的前端人員，現在要從C，C++代碼中找答案了。估計追完這個問題，我會嘗試為Chromium貢獻代碼。
慢著，在這之前，還是搜到一些關于這個錯誤的信息的。但似乎都不怎么靠譜。
比如這里提到，是因為ISP網絡問題，實在無太可能。還有這是神馬居然一個硬件網站但提到了這個錯誤，并且懷疑是殺軟導致Chrome出問題，但殺軟已經在上文被我們排除了。
Chromium 源碼
那么這個錯誤究竟是什么。能不能找到點靠譜的解釋。當然能，讓我們進入到Chromium的源碼中去。
ERR_CONNECTION_RESET被喚起的地方
在Chromium的源碼中搜索該常量名，確實出現很多結果。聯系到我們查看日志發現問題的上下文，是在解析響應頭報的。所以我們定位到http_stream_parser.cc文件，同時注意到有一個文件叫net_errors_win.cc，所以猜測他是定義所有錯誤常量用的，也順便打開之。
經過觀察src/net/base/net_errors_win.cc 其路徑和代碼得知其中多為系統級別的錯誤，似乎跟我們的問題不是很關聯，忽略該文件。
http_stream_parser.cc文件中，ERR_CONNECTION_RESET僅出現一次。這給我們定位帶來了極大的便利。
cpp [chromium]//src/net/base/net_errors_win.cc https://code.google.com/p/chromium/codesearch#chromium/src/net/http/http_stream_parser.cc&q=ERR_CONNECTION_RESET&sq=package:chromium&dr=C http_stream_parser.cc // Returns true if |error_code| is an error for which we give the server a // chance to send a body containing error information, if the error was received // while trying to upload a request body. bool ShouldTryReadingOnUploadError(int error_code) { return (error_code == ERR_CONNECTION_RESET); }
這里定義了一個ShouldTryReadingOnUploadError 的方法，注釋耐人尋味，這個時候，這樣的情景，能否正確解讀注釋成為了比讀懂代碼更重要（這是我在看JS代碼時永遠無法體味到的感覺），下面盡可能對它進行理解：
在嘗試發送一個請求體的時候，讓服務器嘗試發送一個帶錯誤的響應體，如果我們接收到了該錯誤則返回
true
我承認被上面的復雜從句打敗！
那么我們來看這個方法被調用的場景。
現在我們點擊上面的ShouldTryReadingOnUploadError方法，代碼下方出現調用了該方法的地方，一共有兩處。
分別點擊進行查看。
cpp 459行DoSendHeadersComplete方法里進行了調用 int HttpStreamParser::DoSendHeadersComplete(int result) { if (result < 0) { // In the unlikely case that the headers and body were merged, all the // the headers were sent, but not all of the body way, and |result| is // an error that this should try reading after, stash the error for now and // act like the request was successfully sent. if (request_headers_->BytesConsumed() >= request_headers_length_ && ShouldTryReadingOnUploadError(result)) { upload_error_ = result; return OK; } return result; }
雖然不太可能，但也不排除頭部和請求體合并的情況，當所有頭部發送完畢，請求體不一定，此時
result便是需要稍后處理的一種錯誤，這里暫且先返回OK。
cpp 516行另一個DoSendBodyComplete方法里進行了調用 int HttpStreamParser::DoSendBodyComplete(int result) { if (result < 0) { // If |result| is an error that this should try reading after, stash the // error for now and act like the request was successfully sent. if (ShouldTryReadingOnUploadError(result)) { upload_error_ = result; return OK; } return result; }
跟上面類似，如果
result出錯，稍后處理，先返回正常
這也與我們在日志中看到的情況相符，在前面再次錯誤后，這次請求并沒有終止結束，而是嘗試到了第三次并且以成功結束的。
但不管怎樣，從這兩個方法，一個DoSendHeadersComplete， 另一個DoSendBodyComplete，身上能體現出請求確實已經發出去。
TCP RST
另外，在net_error_list.h這個文件的109行，可以準確找到我們在日志中得到的101號錯誤。它的定義如下：
// A connection was reset (corresponding to a TCP RST).
NET_ERROR(CONNECTION_RESET, -101)從括號中的進一步解釋可以知道，它代表TCP連接重置。
TCP
那么問題來了，什么是TCP連接重置？什么會引發TCP連接重置。從這篇文章中有比較詳細的解答。
想要完全解釋，本文似乎是不可能的了。但根據上面的文章，這里可以簡單轉述一下。
什么是TCP連接
它是一種協議。當網絡上一個節點想與另一個節點通信時，雙方需要選建立連接。而這個連接過程需要大家都懂的一種約定，TCP就是事先定好的一種約定，于是我們采用它吧，于是其中一個節點按照這個約定發起一建立連接的請求，另一節點收到后，根據該約定，便能讀懂這個請求里各字段的意思：哦，丫這是想約我呢。
三次握手
繼續上面的例子。A想與B通信，并且使用TCP。
首先A發起一個報文，其中包含自己的地址，想要連接的目標地址，自己用來連接的端口及目標機器的端口,etc.
B收到邀約，并且愿意付約。此刻B需要回傳一個報文，告訴A我愿意跟你連接。
A收到B的肯定應答，到此A與B經歷了三次通信或者說是握手，雙方都沒有異議，連接建立。
而連接斷開的過程也頗為類似。雙方中的一方比如說A先發起一個斷開連接的報文FIN，B收到并確認，然后回傳一個可以斷開的報文FIN給A。此刻A收到并確認。此刻雙方都確認后，連接可以安全斷開，但還會保持一個等待斷開的狀態，大概持續4分鐘，用于之前連接通路上未傳輸完成的數據進行善后。
什么是重置
上面提到了4分鐘的等待時間，而重置RESET便是立即斷開連接的手段。
發生重置的情況
到此重置的作用已然明了。也就是說，重置甚至算不上一個錯誤，它是TCP連接中的一種正常情況。但什么時候會發生重置，如何引起的。
上文列出了三種情況。
SMB Reset
簡單舉例來說，服務器提供了兩個端口445，139進行服務，客戶端同時去請求與這兩個端口連接，服務器返回了兩個端口可以被連接，此刻客戶端擇優選擇一個進行連接，而重置另一個。
Ack, Reset
報文重置發生主要有以下情況：
- 服務器沒有監聽被請求的端口，無法建立連接
- 服務器此刻無法比如沒有充裕的資源用來連接連接
TCP Reset due to no response
由于沒有響應而被重置。當發起連接的一方連續發送6次請求未得到回應，此刻默認他們之間已經通過三次握手建立了連接并且通信有問題，發起的一方將連接重置。
Application Reset
除了上面的情況，找不到TCP內部自己發送的重置，則歸為了這一類。程序內將連接重置。此種情況包含了所有你想得到想不到將連接斷開的情況。有可能是程序內部邏輯重置的，所以不能完全認為此時發生了錯誤。
值得注意的是，上面列出的情況服務器的不確定性導致連接重置的可能性要合理些。Chrome 主動發起URL請求不太可能自己又重置掉，并且沒有理由重置掉后又去重連。
Chrome Dev Tool 中時間線各階段代表的意義
另附注一下Chrome Dev Tool 中請求的時間線各階段代表的意義。
以下內容扒自Chrome 開發者文檔頁，然后我將它本地化了一下下。
Stalled/Blocking
在請求能夠被發出去前的等等時間。包含了用于處理代理的時間。另外，如果有已經建立好的連接，那么這個時間還包括等待已建立連接被復用的時間，這個遵循Chrome對同一源最大6個TCP連接的規則。
「拿我們的情況來說，上面出錯所有的耗時也是算在了這部分里面。網絡面板中顯示的其余時間比如DNS查找，連接建立等都是屬于最后那次成功請求的了」
Proxy Negotiation
處理代理的時間。
DNS Lookup
查找DNS的時間。頁面上每個新的域都需要一次完整的尋路來完成DNS查找。
Initial Connection / Connecting
用于建立鏈接的時間，包括TCP握手及多次嘗試握手，還有處理SSL。
SSL
完成SSL握手的時間。
Request Sent / Sending
Time spent issuing the network request. Typically a fraction of a millisecond.
發起請求的時間，通常小到可以忽略。
Waiting (TTFB)
等待響應的時間，具體來說是等待返回首個字節的時間。包含了與服務器之間一個來回響應的時間和等待首個字節被返回的時間。
Content Download / Downloading
用于下載響應的時間
結論
我相信很多同學是直接跳到這里來了的。事實上我給不出什么解決方案，只能證明前端代碼沒有問題，請求已發。請RD同學接著排查。
另外，利用好Chrome的內部網絡日志chrome://net-internals/#events進行網絡分析是個非常好的選擇，特別是在處理這些調試面板上無法體現的細節問題時。
參考及引用
#1 Chrome stalls when making multiple requests to same resource?
#2 What does “pending” mean for request in Chrome Developer Window?
#3 Evaluating network performance / Resource network timing
#4 Provisional headers are shown
#5 “CAUTION: provisional headers are shown” in Chrome debugger
#6 Chrome 里的請求報錯 "CAUTION: Provisional headers are shown" 是什么意思?
#7 Issue 345643003: Http cache: Implement a timeout for the cache lock
#8 Issue 46104: Pages can get blocked in "Waiting for Cache" for a very long time
#9 Providing Network Details for bug reports
#10 從FE的角度上再看輸入url后都發生了什么
#11 ERR_CONNECTION_RESET 的Chromium 源碼
#12 Chromium Network Stack
#13 Where do resets come from? (No, the stork does not bring them.)
文章列表
留言列表
