R·ex / Zeng


音游狗、安全狗、攻城狮、业余设计师、段子手、苦学日语的少年。

一次对 Chromium 源码分析的经历

问题起因

前几天,我们组的 Leader 在准备内部技术分享的 PPT,是关于 Chrome 底层的一些内容。然而在准备的过程中,发现了 Chrome 在某些情况下会重复请求服务器资源。这是明显不合理的设计,因为 Chrome 并不知道每个请求是否符合幂等性,代替开发者自动重新请求可能会导致不可预知的问题,于是 Leader 便开始寻找问题所在。刚好被我看到了,于是便过去帮一下忙(当了一个小时的小黄鸭),最终我们发现了问题所在。

回家后,我觉得很有必要完全靠自己把这个问题仔细研究一下,毕竟我看到 Leader 的时候他已经追到了相关的代码片段,我并不知道之前发生了什么,以及 Chromium 是个史诗级的巨型项目,自己之前从未接触过如此规模的项目。于是便搜到了 Chromium 的源码开始折腾。

问题复现

这个不合理的设计是:假设在 <body> 中有两个 <link> 各加载了一段 CSS,前者延迟高但是正常返回,后者延迟低但会报错,此时在 F12 的 Network 中会看到如下场景:

  • 请求 HTML
  • 几乎同时请求两个 CSS,状态均为 pending
  • 第二个 CSS 状态变为 failed
  • 第一个 CSS 正常返回
  • 立即重新请求第二个 CSS

一个简单的用于复现的服务端代码如下(使用了 koa):

const Koa = require('koa');
const route = require('koa-route');

const index = `
<html>
<body>
    <link rel="stylesheet" href="1.css?delay=4">
    <link rel="stylesheet" href="2.css?delay=1">
</body>
</html>
`;

const getCSS1 = ctx => new Promise(resolve => {
  console.log('getting 1.css');
  setTimeout(() => {
    ctx.response.type = 'css';
    ctx.response.body = 'body { margin: 0; }';
    resolve();
  }, 1000 * ctx.query.delay);
});

const getCSS2 = ctx => new Promise(resolve => {
  console.log('getting 2.css');
  setTimeout(() => {
    ctx.response.status = 404;
    ctx.response.body = 'Not found';
    resolve();
  }, 1000 * ctx.query.delay);
});

const getIndex = ctx => {
  console.log('getting index');
  ctx.response.body = index;
};

const app = new Koa();
app.use(route.get('/', getIndex));
app.use(route.get('/1.css', getCSS1));
app.use(route.get('/2.css', getCSS2));
app.listen(3000);
console.log('server started, listen :3000');

装好依赖、运行 node index.js 之后,用 Chrome 打开 http://localhost:3000,会在 F12 Network 面板看到如下一幕:

Network 显示 2.css 被额外加载了一次

与此同时,在本地的终端中也应当看到如下文字:

$ node index.js
server started, listen :3000
getting index
getting 1.css
getting 2.css
getting 2.css

下载、编译的简要说明

其实官方文档已经足够详细了,但这儿有几点需要补充一下:

  1. 我用的是跑在 Hyper-V 中的 Ubuntu 18.10,因为当时手头上刚好有这么个镜像。但 Chromium 的构建脚本默认只支持 LTS 版本的 Ubuntu,因此在执行 ./build/install-build-deps.sh 的时候需要在后面加上 --unsupported 参数;
  2. 如果你对之前的提交记录毫不关心,最好在 fetch --nohooks chromium 的时候再加上 --no-history,毕竟里面的几十万次提交记录不是闹着玩的,当然也别手贱执行 git status 之类的操作,基本每执行一次都要卡十秒左右;
  3. 一定需要保证梯子的质量,因为需要从谷歌那边下好多好多的东西……执行 gclient runhooks 的时候,经常会过了很久没有打 Log,我是通过添加 -vv 参数并且开了 Network 监视才确定它确实有在往前走;
  4. 如果你想跑一遍 Doxygen 先生成文档,切记千万不要在 src 目录下跑,至少我给分配的 10 GB 是完全不够用的,而且即使我给 Hyper-V 分配了四个逻辑内核(i7-7700HQ),并给了一天零一夜的时间,仍然没有跑完。

熟悉项目

反正一番折腾之后,Chromium 是跑起来了,但面对这庞大的代码仓库,我还是很茫然,于是去找官方文档。官方文档中,针对开发者的入口在 For Developers,顺着链接我又翻到了 Getting Around the Chromium Source Code Directory StructureDesign DocumentsMulti-process ArchitectureMulti-process Resource Loading,我只关注了一下 Chromium 的代码结构和 Render/Resource 相关的 Class Names,感觉应该是够用了。

依据对这几篇文章的一点基本的了解,我大概知道了自己的目标代码在 contentthird_party/blink 两个文件夹中,里面的代码有定义(xxx.cc)也有实现(xxx_impl.cc),如果要搜某个 Class(例如 AbcDef)所在的文件,可以直接在这两个文件夹中执行 find . | grep abc_def

最终,我把目标定在了 content/renderer/loader/resource_dispatcher.cc 这儿,因为在官方文档中的调用关系图里面,它是负责加载资源的,而且里面有个 MakeRequestID 的成员函数看起来每次请求都会被调用一次,于是我就从这儿开始了。

追踪代码

查看调用过程

在之前的小项目中,我会通过动态调试或者打 Log 的形式来调试,但如此庞大的一个项目,我在不完全了解项目代码间引用、没有 IDE 支持的情况下,每次打一条 Log 完全不足以让我了解代码的运作过程,于是我打算在要关注的地方打一段 Stack Trace。经过一番搜索,发现 Getting Started with Blink Debugging 里面有提到输出 Stack Trace 的函数:

#include <base/debug/stack_trace.h>
// ...
base::debug::StackTrace().Print();

文章里面也提到,由于 base 默认并不在 blink 里面,因此在命令行运行的时候,需要加一个 --no-sandbox 参数,否则就只能修改 gypgn 后重新编译了。

此外,还有个 LOG 宏可以用来打印单条 Log:Seeing all LOG(foo) messages

我试着在 content/renderer/loader/resource_dispatcher.ccMakeRequestID 里面加了这样一句话,并且为了区分明显,又加了个 LOG(INFO) << "------------------------------------ make request id";。增量编译之后执行:./out/Default/chrome http://host_ip:3000 --log-level=0 --no-sandbox,发现这个函数一共执行了 5 次,看 Stack Trace 的情况是:

  • 除了第一条以外都是通过 ResourceFetcher 加载的,说明第一条是网页本体;
  • 第 2、3 条里面有个 ResourcePreloader,是由 HTMLDocumentParser 调用的,难道有预加载的过程?
  • 第 4 条看起来才更像是真正的 <link> 的处理,因为里面包含了 HTMLLinkElement::Process
  • 第 5 条没看懂,因为既没有 HTMLLinkElement 也没有 HTMLDocumentParser,直接就出现了 ResourceFetcher

由于没有输出 URL,因此无法断定特别具体,但 Stack Trace 告诉我,接下来应该重点关注 HTMLDocumentParserResourcePreloader

不为人知的预加载

打开 third_party/blink/renderer/core/html/parser/html_document_parser.cc,我在里面发现了一个叫 BackgroundHTMLParser 的类(在同目录下的 background_html_parser.cc 中),类的开头就是一大段注释,大体意思是:当用户处于高延迟和高带宽的网络,并且设备的 CPU 性能比较强的时候,我们没必要提前解析太多的 Token。

搜了一下,大概明白了意思:Chromium 有个“Preload”的机制,当接收到 HTML 代码时,会有两个 Parser,主 Parser 完全遵循 W3C 规范,遇到资源则阻塞,但 Background Parser 会一直提前解析(如果比主 Parser 快了太多则会暂停一下节约内存),遇到了资源就扔到 Preload List 里面预先加载,这样可以稍微节约一点加载时间,因为主 Parser 在解析 CSS / 执行 JS 时,网络资源是空闲的。

实际上,预加载的内容不止页面中的资源,我还看到了这样一行代码:如果没有违反 Policy,会预加载剪贴板中的内容。

然后……我就卡住了。

更多的调试信息

按照网上的说法,我在启动时添加了 --v=1 的参数,然后……就被各种 Verbose 信息刷屏了。但是我刚才打印的那一长串 Log 还在,我可以直接搜索它们:

[2615:2615:0407/192057.682598:VERBOSE1:resource_fetcher.cc(1126)] Loading Resource for "http://172.18.74.177:3000/1.css?delay=4"
[2615:2615:0407/192057.683214:VERBOSE1:memory_cache.cc(139)] MemoryCache::add Added "http://172.18.74.177:3000/1.css?delay=4", resource 0x1541300b9c70
[2615:2615:0407/192057.684630:INFO:resource_dispatcher.cc(118)] ----------------------------------------- make request id
[2562:2568:0407/192057.685820:VERBOSE1:safe_browsing_url_checker_impl.cc(208)] SafeBrowsingUrlCheckerImpl checks URL: http://172.18.74.177:3000/1.css?delay=4
[2615:2615:0407/192057.687107:VERBOSE1:resource_fetcher.cc(1126)] Loading Resource for "http://172.18.74.177:3000/2.css?delay=1"
[2615:2615:0407/192057.687616:VERBOSE1:memory_cache.cc(139)] MemoryCache::add Added "http://172.18.74.177:3000/2.css?delay=1", resource 0x1541300ba560
[2594:2602:0407/192057.688691:VERBOSE1:network_delegate.cc(32)] NetworkDelegate::NotifyBeforeURLRequest: http://172.18.74.177:3000/1.css?delay=4
[2615:2615:0407/192057.688657:INFO:resource_dispatcher.cc(118)] ----------------------------------------- make request id
[2594:2602:0407/192057.688869:VERBOSE1:network_delegate.cc(32)] NetworkDelegate::NotifyBeforeURLRequest: http://172.18.74.177:3000/1.css?delay=4
[2562:2568:0407/192057.689635:VERBOSE1:safe_browsing_url_checker_impl.cc(208)] SafeBrowsingUrlCheckerImpl checks URL: http://172.18.74.177:3000/2.css?delay=1
[2594:2602:0407/192057.690040:VERBOSE1:spdy_session_key.cc(29)] SpdySessionKey(host=172.18.74.177:3000, proxy=direct://, privacy=0
[2594:2602:0407/192057.693044:VERBOSE1:network_delegate.cc(32)] NetworkDelegate::NotifyBeforeURLRequest: http://172.18.74.177:3000/2.css?delay=1
[2594:2602:0407/192057.693216:VERBOSE1:network_delegate.cc(32)] NetworkDelegate::NotifyBeforeURLRequest: http://172.18.74.177:3000/2.css?delay=1

往下慢慢翻,发现了 404 之后相关的日志:

[2594:2602:0407/192058.698356:VERBOSE1:http_stream_parser.cc(1032)] ParseResponseHeaders() content_length = "9" headers = "HTTP/1.1 404 Not Found
Content-Type: text/plain; charset=utf-8
Content-Length: 9
Date: Sun, 07 Apr 2019 11:20:58 GMT
Connection: keep-alive"
[2594:2602:0407/192058.699738:VERBOSE1:loader_util.cc(45)] To buffer: http://172.18.74.177:3000/2.css?delay=1
[2594:2602:0407/192058.710771:VERBOSE1:data_pipe_producer_dispatcher.cc(459)] Data pipe producer 10504323316279946186 notifying peer: 9 bytes written. [control_port=4312D39B130DEA23.DB5199660A24C1FD]
[2594:2602:0407/192058.711699:VERBOSE1:data_pipe_producer_dispatcher.cc(94)] Closing data pipe producer 10504323316279946186
[2594:2602:0407/192058.713919:VERBOSE1:data_pipe_consumer_dispatcher.cc(580)] Data pipe consumer 10504323316279946186 is aware that 9 bytes were written. [control_port=303157F17FC3F552.54AC4F1B9449B945]
[2615:2615:0407/192058.717170:VERBOSE1:memory_cache.cc(174)] Evicting resource 0x1541300ba560 for "http://172.18.74.177:3000/2.css?delay=1" from cache

纳尼,又多了一个 memory_cache.cc,结合一下代码里面的内容,发现是这样的:

  • MemoryCache 通过 URL 生成了一个哈希值(例如 0x1541300b9c70);
  • 将 Resource 加入到 resource_maps_ 这个 Map 中(我也不知道为啥后面多个下划线),键就是刚才生成的哈希值;
  • 开始加载资源(可以看到我打的 make request id);
  • 若加载失败,则将其从 resource_maps_ 中删除;

至于 ResourceFetcher 也在 Log 里面被提到了(resource_fetcher.cc(1126)),我看了一下是一个叫 ResourceFetcher::CreateResourceForLoading 的函数,里面的逻辑是这样的:

DCHECK(!IsMainThread() || params.IsStaleRevalidation() ||
       !GetMemoryCache()->ResourceForURL(params.GetResourceRequest().Url(),
                                         cache_identifier));

RESOURCE_LOADING_DVLOG(1) << "Loading Resource for "
                          << params.GetResourceRequest().Url().ElidedString();

所以大概流程应该是:如果 Memory Cache 里面没有这个资源,就开始加载,加载时会先将资源扔到 Memory Cache 中,如果加载失败则从 Memory Cache 中将其移除。那么这个 CreateResourceForLoading 究竟是被哪些地方调用了呢?我从这个函数内部打了一个 Stack Trace,发现 PreloadHelper::StartPreloadLinkLoader::LoadStylesheet 都会调用 CSSStyleSheetResource::Fetch,从这儿会进入到 ResourceFetcher 里面,然后就是 MemoryCache 了。从 Log 的先后顺序来看,Preload 发生在 Link 之前。

得出结果

结合刚才的种种迹象,我得出一个结论:

  • 页面上有两个 Parser,其中 Background Parser 先开始预加载资源,而另一个 Parser 由于遵循了 W3C 规范,可能会被各种资源 Block 住;
  • 预加载资源的时候会使用 ResourceFetcher,它会先将资源放在一个 Map 中,然后开始加载其内容,若失败则将其从 Map 中移除;
  • 主 Parser 会调用 LinkLoader::LoadStylesheet 来尝试加载资源,若 Memory Cache 里面已经有了,则直接使用,否则会调用 ResourceFetcher 开始加载;
  • 具体发生的事情是这些:

    • 开始解析 HTML
    • Background Parser 预加载 1.css 并添加至 Map
    • Background Parser 预加载 2.css 并添加至 Map
    • 主 Parser 解析到了 1.css
    • 主 Parser 发现 1.css 在 Map 中并且还没加载完,慢慢等
    • (一秒后)2.css 由于加载失败被移出 Map
    • (三秒后)1.css 加载完了,主 Parser 不用等了
    • 主 Parser 解析到了 2.css
    • 主 Parser 发现 2.css 不在 Map 中,于是开始加载
    • (一秒后)2.css 由于加载失败被移出 Map
    • 加载 favicon.ico(这就是我刚才不知道是啥玩意儿的一个请求)

最后的 favicon.ico 是真蛋疼,在 F12 Network 里面不显示,看了 Log 之后才发觉。

验证结果

如果真的跟上面写的一样,那么以下的几种情况应该都成立:

  • 错误请求在后面,但加载的更慢,这样不会重复加载
<body>
  <link rel="stylesheet" href="1.css?delay=1">
  <link rel="stylesheet" href="2.css?delay=4">
</body>
  • 错误请求在前面,也加载的更快,这样不会重复加载
<body>
  <link rel="stylesheet" href="2.css?delay=1">
  <link rel="stylesheet" href="1.css?delay=4">
</body>
  • 错误请求在前面,但加载的更慢,这样不会重复加载
<body>
  <link rel="stylesheet" href="2.css?delay=4">
  <link rel="stylesheet" href="1.css?delay=1">
</body>
  • 不管两个请求如何,只要都在 <head> 里,就不会重复加载
<head>
  <link rel="stylesheet" href="1.css?delay=4">
  <link rel="stylesheet" href="2.css?delay=1">
</head>

最后一点可能比较奇怪,但看了源码就会知道,只有在 <body> 里面的资源才会导致主 Parser 被阻塞(我看到了一段注释,大概的意思是“在 <head> 中的资源不应该阻塞 Parser,应该被尽可能早的加载”),因此 <head> 里面的内容不会让主 Parser 重复发请求。

经过实际测试,上述几种情况都是符合预期的。此外,不光是 <link>,在 <body> 中的 <script> 也可能会导致这种问题,但 <img> 就不会,究其原因,可能是因为 <img> 不会被预加载。

修复方案

可能是因为我比较菜,暂时没有想到修复方案,之前跟 Leader 讨论过“404 的时候不从 Map 中删除”、“等主 Parser 过去之后再将其删除”等方案,要么可能会产生其它问题,要么对整个代码的改动太大,似乎都不是很好的修复方案。

鉴于其它主流浏览器都没有这个问题,Chromium 团队也没有修复这个的动机,而且在 <body> 中嵌入 <link> 并不是一个特别好的做法,因此如果对重复加载的问题比较在意,也只能把 <link> 写到 <head> 里了。

由于水平有限,而且是第一次翻阅这样的巨型项目,错误在所难免。如果文中有什么错误敬请指出。

版权声明:除文章开头有特殊声明的情况外,所有文章均可在遵从 CC BY 4.0 协议的情况下转载。

这是我们共同度过的

第 1426 天