记一次生产请求耗时的问题

最近发现lb上记录的request_time比upstream_response_time大的比较多，例如upstream_response_time记录是0.062，request_time记录的就是5.064等等。整个耗时很反常。并且出现这个问题基本上都是一个返回值比较大的接口，基本上返回值是100K左右。领导让定位一下这个问题。

先说下咱们的架构的背景，是这样的
阿里云的SLB-------咱们本身的LB----------WEB机器

定位方向错误

跟踪这个问题以后，一直以为 LB上记录的upstream_response_time的时间有问题，我的以为100K的请求0.0xx秒没法完成，从这个入口查了一段时间，没有任何结果。固然也是收获的，协助WEB的同事发现有些请求的CACHE没有使用上。后来以为应该钻牛角了，第一个Nginx的upstream_response_time确定是没有问题的；第二个LB到WEB是都是内网访问，快是必然的。后来抓包也确实证实了LB到WEB特别快，upstream_response_time的时间是正确无误的。

Nagle 算法的问题？

排除掉upstream_response_time记录错误以后，一直没有发现。就看了些资料，学习了下课程。看了下极客时间
Linux性能优化实战 课程，40 | 案例篇：网络请求延迟变大了，我该怎么办？
看完以后，以为可能真的是Nagle 算法的问题。解释下Nagle 算法，Nagle 算法，是 TCP 协议中用于减小小包发送数量的一种优化算法，目的是为了提升实际带宽的利用率。大概意思就是，合并TCP的小包，提升网络带宽的利用率。以为多是Nagle 算法的问题，就把一台LB的tcp_nodelay 打开了几小时，发现问题依然存在。那基本就排除Nagle 算法的问题。
后来仔细琢磨了一下，跟Nagle 算法应该没有关系，Nagle 算法的延迟是40ms才对，咱们这个基本上是5秒。

lingering close 的问题

排除掉Nagle 算法的问题以后，又没有任何方向了。不知道怎么追查了。后来又抓包查看，没有发现有价值的线索。可是肯定没有延迟4秒的，都是延迟5秒的。这是一个特别重要的线索。当时以为应该有一个默认的配置是5秒。http://nginx.org/en/docs/http/ngx_http_core_module.html#
nginx http_core_module里面搜索下5s，发现了lingering_timeout 5s; lingering_timeout是个什么鬼？后来找到一篇跟咱们很相似的问题的文章。文章里面很详细的解释了lingering_timeout。
http://shibing.github.io/2016/11/18/nginx%E7%9A%84%E5%BB%B6%E8%BF%9F%E5%85%B3%E9%97%AD-lingering-close/

下面的这些解释都来自上面的文章
该问题是由 Nginx 的延迟关闭（lingering close）链接致使的。Nginx 为了可以平滑关闭链接，采用了延迟关闭，它的工做方式以下：Nginx 在给客户端发送完最后一个数据包后会首先关闭 TCP 链接的写端（TCP 是全双工协议，任何一端都便可读也可写），表示服务端不会再向客户端发送任何数据，可是不会当即关闭 TCP 链接的读端，而是等待一个超时，在超时到达后若是客户端尚未数据发来，Nginx 才会关闭TCP的读端，从而关闭整个链接，而后再输出日志。另外一方面，Nginx 是在关闭链接后才输出日志，因此在输出日志以前响应早就发送给了用户，所以对业务几乎没有影响。可是这也会致使 requset_time 值变得不许确，使其失去统计意义，开启 Keep-Alive 能够部分解决这一问题。

在 Nginx 发送完数据包并进入延迟关闭链接流程后，若是客户端在 lingering_timeout 时间内没有进行任何操做，那么就会关闭与客户端的链接而后输出日志，这就会致使致使访问日志滞后 lingering_timeout 才输出。咱们线上并无对该参数进行配置，那么会采用默认值，正好是5秒，与实际状况吻合。另外若是使用长链接，Nignx 在请求结束后不须要关闭链接而直接输出日志，那么就不会有这个问题，这也就解释了为何开启 Keep-Alive 后问题消失。

基本上是能够肯定是lingering_timeout的问题，把生产的一台的lingering_timeout的参数改成4s，发现5s的消失，4s的出现。知道这个缘由以后，就能肯定，其实真正的耗时有多是2S 3S，只不过延迟关闭了，写日志的时间是5S。文章也介绍了只要客户端设置keep-alive长链接，Nginx就不会关闭链接，写日志时间就会快不少。可是阿里云的SLB不能开启长链接，由于这个问题，对咱们来讲是无解的，咱们能够将lingering_timeout设置短一点，可是延时关闭的问题是不可避免的。好在是咱们知道了缘由，并非真正的处理慢了，只不过是延时关闭致使日志时间有误。

------------------------------------end
一块儿关注高性能WEB后端技术，关注公众号