关于页面请求发起后，经过F12查看到，被挂起页面中stalled花费很长时间问题的追查

时间 2019-11-19

标签关于页面请求发起经过 f12 查看挂起 stalled 花费很长时间问题追查栏目 Java 繁體版

原文原文链接

请求刚一发出，timing中显示是这样的

有时候过了几十秒以后才响应返回，页面加载完成。html

已下内容纯粹是转载，只为作个记录。方便本身后续再次遇到问题时找到解决方案。前端

本文前戏较多，务实的同窗能够直接跳到文末的结论。html5

由「钢的琴」网友脑洞大开延伸出了吉的他二的胡琵的琶，以及后来许嵩的「苏格拉没有底」，是否能够再拓展一下，获得哥本不爱吃哈根，哈根爱达斯等剧情乱入的关系。git

上面跟本文要讨论的主题有什么关系？github

不要紧。web

缘起

有用户反馈内部MIS系统慢，页面加载耗时长。前端同窗们开组会说起此事，如何解决慢的问题。ajax

最致命的是：偶发！你不能准确知道它抽风的时间点，没法在想要追查问题的时候必现它。这只是一方面，另外，慢的可能实在太多了，那么问题来了，是前端致使的仍是后端的问题？算法

对慢的定义也有待商榷，多久算慢？若是这个页面加载大量数据耗时增长那我认为这是正常的。但这个时限超过了一个合理的天然值，就变得不那么正常了，好比四五十秒，一分多钟。chrome

最奇葩的是，如此久的耗时竟然不会报超时错误，而是拿到正确返回后将页面呈现了出来！json

可能的缘由

初步猜想

初步的猜想多是后端迟迟未返回形成浏览器处于等待状态。这个猜想是很合乎逻辑的，至少可以很合理地解释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仅出现一次。这给咱们定位带来了极大的便利。

[chromium]//src/net/base/net_errors_win.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方法，代码下方出现调用了该方法的地方，一共有两处。

分别点击进行查看。

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。

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请求不太可能本身又重置掉，而且没有理由重置掉后又去重连。

进一步解读日志文件

上面Chromium源码部分的求证多少带有猜想成分。不妥。

由于没找到关于Chrome net-internal 日志的官方文档什么的，自身去解读始终是有局限的。不如提个ISSUE让Chromium开发人员来搭一把手吧。遂向Chromium提交ISSUE，请戳此查看，虽然我不认为如今遇到的这个问题跟Chrome有关而且属于Chrome的Bug，目的仅仅是看他们可否帮忙给出合理的日志解读来定位问题。

三天后（有点热泪盈眶），有同窗回复，将日志所体现的问题诊断得彷佛颇有道理，可信。

1) We have a bunch of connections to qa.tieba.baidu.com, all were used successfully, and are now idle. 2) They all silently die for some reason, without us ever being informed. My guess is your personal router times out the connection, but this could also be your ISP, the destination server, or ever a real network outage (A short one) that prevents us from getting the connection closed message. 3) There’s a new request to qa.tieba.baidu.com. We try to reuse a socket. After 21 seconds, we get the server’s RST message (“I don’t have a connection to you.”). Since it was a stale socket, we’re aware this sometimes happens, so we just retry…And get the next idle socket in the list, which, after 21 seconds, gives us the same reset message. We try again, for the same reason. This time we don’t have another stale socket to try, so we use a fresh one. The request succeeds.

The real problem here is something is taking 21 seconds to send us the RST messages, despite the fact that a roundtrip to the server you’re talking to only takes about 100 milliseconds.

「以前有过不少成功的链接」，确实，由于出现加载缓慢的状况是偶发的，这以前有过不少正常的不卡的请求存在过。这里没有异议。
「他们都以未知的缘由被断掉了」，由于不是正常地断开链接，因此客户端也就是浏览器不知道当前与服务器的TCP链接已经断开，傻傻地保留着与服务器链接的socket，注意，此时已经发生信息的不对等了，这是问题的根源。至于什么缘由，给出了可能的缘由：路由器认为链接超时将其断掉，同时不排除ISP（互联网服务提供商）的缘由，服务器暂时的停运抽风等。无论怎样，客户端浏览器没有收到链接断开的信息。
在上面的基础上，咱们去发起一次新的请求。此时浏览器但愿重用以前的链接以节省资源，用以前的一个socket去发起链接。21秒后收到服务器返回的重置信息（意思是服务器告诉浏览器：我和你之间没有链接），不要紧，上面提到，咱们有不少能够重用的链接，因而浏览器从新从可用的链接里面又选择了一个去进行链接，不幸的是，一样的状况再次发生，21秒后收到服务器的重置信息。这体如今日志上就是第二次重试失败。到第三次，由于前面浏览器认为能够重用的链接如今都被正确地标为断开了，没有新的可用，因而此次浏览器发起了全新的请求，成功了！

总结出来，两个问题：

为何以前成功的链接不正常的断开了？服务器配置或者网络缘由？
是什么让浏览器21秒后才收到重置信息？服务器做出反应过慢仍是网络缘由？

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

发起请求的时间，一般小到能够忽略。

Waiting (TTFB)

等待响应的时间，具体来讲是等待返回首个字节的时间。包含了与服务器之间一个来回响应的时间和等待首个字节被返回的时间。

Content Download / Downloading

用于下载响应的时间

结论

我相信不少同窗是直接跳到这里来了的。事实上我给不出什么解决方案，但能排除前端代码引发问题的可能性。

具体来讲，可以获得的结论有如下几点：

请求成功构造，失败状况下也能够看到正常的请求头被打印出来了的
能够确定的是在与服务器创建链接时被Shut down了，参考上面关于链接重置的部分会更有意义一些
参考上面「进一步解读日志文件」部分，来自Chromium开发者的回复中对日志文件的解读更加合理些，浏览器与服务器的链接不正常断开是致使问题的根源，以致于影响了后面对链接的重用
21秒的等待仍然是个未知数，不知道有何不可抗拒的外力促使浏览器21秒后才收到服务器的重置信息。此处浏览器与服务器的失联缘由有待查证

最后寄但愿于RD同窗跟进，协助排查服务器链接及后端代码的部分。FE同窗会保持持续关注。