nginx 超时问题排查

[vislee]

概述

• 问题1: 源站响应慢，当客户端超时过早的关闭连接时，nginx会打印一条499的access日志。这个时候我们需要排查到底是和上游的tcp握手包丢了，还是源站响应慢。$upstream_connect_time能说明问题么。
• 问题2: nginx返回502，到底是nginx没连上后端，还是后端返回的。$upstream_status能说明问题么。

对于问题1的这两种情况error log都不会记录错误信息。 此时我们一般会看access日志的这个变量$upstream_connect_time，文档表述：

keeps time spent on establishing a connection with the upstream server (1.9.1) ...

建立起握手所消耗的时长。如果是1.15.7之前的nginx版本，那么你会发现日志是一个'-'。根据文档说明应该是没连上源站服务器。 其实不是这样的。

对于问题2$upstream_status是保存了从上游响应的状态码，但是502不一定是上游返回的状态码，可能是没有活着的上游。

keeps status code of the response obtained from the upstream server. Status codes of several responses are separated by commas and colons like addresses in the $upstream_addr variable. If a server cannot be selected, the variable keeps the 502 (Bad Gateway) status code.

排查思路

• 问题1:

1.15.7之前的代码，从r->upstream_states数组从复制值，并且判断该数组的结果状态码没有被赋值就不会取数组的值。因此无论是否连接上后端，变量$upstream_connect_time都为'-'。 1.15.7代码逻辑改了，$upstream_connect_time保存的也不仅仅是连上后端所消耗的时间了，从发起连接到上游有响应所消耗的时间。如果网络一直超时未返回该值为'-'，如果网络返回rst或者建立起连接了该值就是耗费的时长。即使因为proxy_connect_timeout设置超时导致返回504该值也是'-'，但是如果是因为net.ipv4.tcp_syn_retries太小导致的超时，则该字段会有值。无论是哪种超时都会有错误日志。

• 问题2:

从nginx代码来看，很多种情况会导致502，网络上发生的连接错误，没有活着的后端、ssl握手时的错误、发请求发生的错误、接受请求发生的网络错误、响应头无效等。都会导致502，并且会记录到$upstream_status变量，因此该字段是502也不能说明是源站返回的，可能是nginx自己的。

总结：

• 502 Bad Gateway： 表示内核明确拒绝了连接，包括网络层的rst或者icmp报文导致的内核通知、net.ipv4.tcp_syn_retries设置太小导致内核事件、没有活着的后端。
• 504 Gateway timeout： 表示是超时，包括 因proxy_connect_timeout连接后端超时，后端超时未返回。 $upstream_connect_time： 表示的是从发起syn包到nginx收到内核对该连接的事件所消耗的时长，因此该字段有数据并不代表成功连接到后端。