返回结果对比:
上面的对比意义不大,但还是要做的,万一发现有价值的情报了呢。
一次失败的尝试解决问题时,习惯性地看有没有人已经碰过到类似问题,这样做的好处很明显: 如果有,站在巨人的肩上轻松地牛逼着; 如果没有,这是个机会。
于是信心满满地出发了,因为根据一条互联网准则,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 网络面板截图: