2016年11月4日一个普通的周五晚上。

晚上九点多我正准备下班突然客服的同事在群里说有用户反馈网站有时候打不开有时候加载很慢已经有好几个用户投诉了。

我心里咯噔一下赶紧打开电脑开始排查。

没想到这一排查就是一夜。

一、问题现象

我先看了一下服务器的监控CPU、内存、带宽、连接数都正常没有异常。网站我自己打开也很正常速度很快。

但是用户反馈确实有问题。我让客服问了一下用户具体的情况收集到了几个关键信息：

  1. 只有部分用户遇到：不是所有用户都遇到这个问题只有部分用户遇到。
  2. 有时候打不开有时候很慢：不是一直打不开而是有时候打不开有时候加载很慢要等十几秒甚至超时。
  3. 只有Chrome浏览器：遇到问题的用户用的都是Chrome浏览器。用Firefox、IE、Safari的用户都正常。
  4. 刷新一下可能就好了：遇到问题的时候刷新一下页面有时候就正常了。但是过一会儿可能又会出现。
  5. 清缓存没用：用户试了清缓存、清Cookie、换网络都没用还是会出现。

从这些信息来看这个问题很奇怪。服务器正常我自己打开正常只有部分用Chrome的用户遇到而且时好时坏。

这说明问题可能不是服务器的问题而是和浏览器有关或者和网络有关。

二、排查过程

确认了问题现象我开始排查。

第一步：复现问题

排查问题第一步就是要能复现问题。只有复现了才能进一步排查。

但是我自己用Chrome打开网站一直正常复现不了。我试了清缓存、清Cookie、隐身模式、换网络都复现不了。

我又让几个同事用Chrome打开也都正常复现不了。

这就麻烦了复现不了怎么排查？

我想了想可能和用户的网络环境有关。遇到问题的用户可能用的是特定的网络比如某个运营商的网络或者公司的内网。

我让客服问了一下遇到问题的用户用的是什么网络。结果用户用的网络各种各样有电信的有联通的有移动的有家里的WiFi有公司的网络没有规律。

这就更奇怪了。

第二步：看日志

复现不了我只能先看日志看看能不能从日志里找到一些线索。

我先看了Nginx的访问日志看看有没有异常的请求。

看了半天发现访问日志都正常没有异常的状态码没有超时的请求。所有的请求都是200或者304响应时间也都正常几十毫秒到几百毫秒。

然后我看了Nginx的错误日志也没有异常的错误。

PHP的错误日志也看了没有异常。

数据库的慢查询日志也看了没有慢查询。

日志里什么异常都没有。这说明问题可能不在服务器端而在客户端或者网络传输的过程中。

第三步：想到了HTTP/2

排查到这里我有点一筹莫展了。服务器正常日志正常复现不了只有部分Chrome用户遇到问题。

我突然想到了一个事情：我们的网站上个月刚开启了HTTP/2。

HTTP/2是HTTP协议的新版本2015年才正式发布。2016年的时候HTTP/2还比较新支持的浏览器不多只有Chrome、Firefox、Safari的最新版本才支持。而且服务器端的支持也不太成熟Nginx的HTTP/2支持也是刚出来不久。

而且HTTP/2有很多新特性比如多路复用、头部压缩、服务器推送等。这些新特性虽然能提高性能但是也可能引入新的Bug。

而且问题只有Chrome用户遇到其他浏览器都正常。这会不会和HTTP/2有关？因为Chrome是最早支持HTTP/2的浏览器而且支持得最完善。其他浏览器可能还没支持HTTP/2或者支持得不好所以用的还是HTTP/1.1就不会遇到问题。

想到这里我觉得很有可能就是HTTP/2的问题。

第四步：验证猜想

为了验证我的猜想我做了一个测试：把Nginx的HTTP/2支持暂时关掉看看用户的问题还会不会出现。

我修改了Nginx的配置把listen 443 ssl http2;改成了listen 443 ssl;，也就是关掉了HTTP/2只用HTTP/1.1。然后重启了Nginx。

关掉HTTP/2之后我让客服联系了之前遇到问题的用户问问他们现在网站正常了吗。

结果用户反馈关掉HTTP/2之后网站就正常了再也没有出现过打不开或者很慢的情况。

果然就是HTTP/2的问题！

第五步：深入排查找根因

确认了是HTTP/2的问题接下来就是要找到具体的根因为什么HTTP/2会导致这个问题。

我先查了一下Nginx的版本。我们用的Nginx是1.10.1这个版本是2016年5月发布的HTTP/2的支持是从1.9.5版本开始加入的到1.10.1也才半年多的时间还不太成熟。

然后我查了Nginx的changelog看看1.10.1之后的版本有没有修复HTTP/2相关的Bug。

一查发现1.10.2版本修复了好几个HTTP/2的Bug其中有一个Bug描述是："修复了在某些情况下HTTP/2请求可能被挂起的问题。"

这个Bug的描述和我们遇到的问题很像！请求被挂起就会导致网站打不开或者加载很慢。

而且这个Bug可能只有在特定的条件下才会触发所以只有部分用户遇到而且时好时坏。

为了进一步确认我又查了一下这个Bug的详细信息。发现这个Bug是Nginx的HTTP/2实现在处理某些特定的请求头的时候会出错导致请求被挂起。而Chrome在某些情况下会发送这种特定的请求头所以只有Chrome用户会遇到这个问题。其他浏览器不会发送这种请求头所以不会遇到。

根因终于找到了！就是Nginx 1.10.1的HTTP/2实现有一个Bug在某些情况下会导致请求被挂起而Chrome正好会触发这个Bug。

三、解决方案

找到了根因解决方案就很简单了：升级Nginx到1.10.2或者更高的版本。

但是当时已经是凌晨两点多了升级Nginx有风险万一升级出问题影响线上业务就麻烦了。而且升级Nginx需要重新编译或者安装新的包需要一些时间。

所以我决定先临时关掉HTTP/2用HTTP/1.1保证网站正常。然后等第二天白天业务低峰期的时候再升级Nginx。

当天晚上我就关掉了HTTP/2网站恢复正常了。用户也没有再反馈问题了。

第二天白天我在测试环境升级了Nginx到1.10.2测试了各种功能都正常。然后在业务低峰期把线上的Nginx也升级到了1.10.2然后重新开启了HTTP/2。

升级之后观察了几天没有再出现之前的问题。用户也没有再反馈。HTTP/2的Bug彻底解决了。

而且升级Nginx之后HTTP/2的性能也更好了网站的加载速度也更快了。

四、经验总结

这次HTTP/2 Bug的排查给了我很多经验和教训。

1. 线上故障排查第一步是复现

排查线上故障第一步就是要能复现问题。只有复现了才能进一步排查找到根因。如果复现不了排查起来就会很困难只能靠猜靠看日志。

这次我们一开始复现不了排查了很久都没有头绪。后来还是靠猜想关掉HTTP/2才验证了问题。

所以遇到线上故障首先要想办法复现问题。可以问用户具体的操作步骤网络环境浏览器版本等尽量模拟用户的环境复现问题。

2. 日志很重要但是不是万能的

日志是排查问题的重要工具。很多问题都能从日志里找到线索。

但是日志不是万能的。有些问题比如协议层的问题网络层的问题可能不会在应用日志里留下痕迹。这次HTTP/2的Bug，Nginx的访问日志和错误日志都没有异常因为请求被挂起了根本没有到达应用层所以日志里什么都没有。

所以排查问题不能只看日志还要考虑协议层、网络层、客户端等其他层面的问题。

3. 新特性要谨慎上线

HTTP/2是比较新的协议2015年才正式发布2016年的时候还不太成熟。服务器端的支持浏览器端的支持都可能有Bug。

我们在HTTP/2还不太成熟的时候就上线了HTTP/2导致遇到了Bug。虽然HTTP/2能提高性能但是也带来了风险。

所以对于新特性、新技术要谨慎上线。最好先在测试环境充分测试然后灰度上线先让部分用户使用观察一段时间没有问题再全量上线。而且要有回滚方案万一出问题能快速回滚。

4. 升级软件版本要关注changelog

这次我们能快速找到根因是因为我查了Nginx的changelog发现1.10.2版本修复了类似的Bug。

所以平时要关注使用的软件的changelog特别是大版本更新或者修复了安全Bug、严重Bug的版本。及时升级软件版本能避免很多已知的Bug。

但是升级版本也要谨慎要先在测试环境测试没有问题再升级线上。而且要备份配置备份数据万一升级出问题能快速回滚。

5. 协议层的Bug排查起来很痛苦

这次HTTP/2的Bug属于协议层的Bug。协议层的Bug排查起来真的很痛苦。因为它涉及到客户端和服务器端双方的协议实现可能是客户端的问题可能是服务器端的问题也可能是双方的实现不兼容。

而且协议层的Bug往往不会在应用日志里留下痕迹需要用抓包工具比如Wireshark、tcpdump抓包分析才能找到问题。而抓包分析需要对协议很熟悉否则也看不懂。

所以平时要多学习网络协议的知识比如HTTP、TCP、SSL/TLS等遇到协议层的问题才能从容应对。

五、写在最后

线上出了个HTTP/2协议的Bug我排查了一夜。

从晚上九点到凌晨两点排查了五个多小时终于找到了根因解决了问题。虽然很累但是解决问题之后那种成就感也是无法形容的。

这次经历让我对HTTP/2协议有了更深的理解也让我积累了线上故障排查的经验。

线上故障是每个程序员都可能遇到的。遇到故障不要慌张要冷静分析一步步排查。先复现问题再看日志再猜想验证最后找到根因解决问题。

而且平时要多学习多积累遇到问题才能从容应对。技术是不断发展的新的协议新的框架新的工具层出不穷。我们要保持学习的热情不断提升自己的技术能力。

最后用一句话结尾：

"排查Bug的过程虽然痛苦但是解决Bug的那一刻一切都值得了。"

愿我们都能在排查Bug的过程中不断成长不断进步。