【发布时间】:2017-10-11 22:31:25
【问题描述】:
我们确实遇到了 nginx 超时的奇怪生产问题。超时如下:
"upstream timed out(110: Connection timed out)"
这里,上游服务器是jetty,运行在同样运行 nginx 的主机上。 Jetty 在端口 8080 上运行,而 nginx 在 443 上运行。
检查了上述错误后,我验证了jetty日志和nginx日志的日志。尽管 jetty 在不到一秒的时间内返回响应,但发送到 nginx 的响应是 delayed 接近 60 secs。并且 nginx 正在计时,在 60 秒后触发超时警报,http 响应代码为504。这正在发生intermittently。
以下是 jetty 和 nginx 的超时请求日志。
码头日志:
{"evt":1494519426927,"intelId":"50","intelSeq":112506,"intelVer":"1","time":"2017-05-11T16:17:06.927Z"," uiCorrelationIdV1":"SUI-1494519425839-42047","threadName":"qtp754853679-357","wResource":"http://m.xxx.com/search/facet/women/womens-handbags-9780510203/shoulder/_/N-53f3Z7hk9Z1z0roil","wMethod":"GET","wStatus":200,"wDurationMicros":1087801 ,"wJlpLocation":"","wFwdFor":"NADA","wHostHdr":"m.xxxx.com","wReferer":"https://m.xxxx.com/search/facet/women/womens-handbags-9780510203/_/N-53f3Z7hk9?search-term=Bags&sortBy=priceLow&facet=Handbag%20Style","wHttpVer":" HTTP/1.0","wWsgClientIp":"80.192.191.2","wSrcIP":"127.0.0.1","wUserAgent":"Mozilla/5.0 (iPhone;CPU iPhone OS 10_3_1 类似 Mac OS X)AppleWebKit/603.1.30 (KHTML, 像 Gecko) 版本/10.0 Mobile/14E304 Safari/602.1","intelCropped":false,"intelLength":834}
Nginx 日志:
2017-05-11T17:18:09+01:00 intelId="56" intelVer="2" wMethod="GET" wResource="/search/facet/women/womens-handbags-9780510203/across-body/should//N-53f3Z7hk9Z1z0roq4Z1z0roil?search-term=Bags&sortBy=priceLow&facet=Handbag%20Style" wStatus="504" wCacheStatus="MISS" wSrcIP="172.17.233.135" wSize="176" wDurationSeconds="60.001" wHostHdr="m.xxx.com" wReferer="https://m.xxxx.com/search/facet/women/womens-handbags-9780510203/shoulder//N-53f3Z7hk9Z1z0roil?search-term=Bags&sortBy=priceLow&facet=Handbag%20Style" wSSL="on" wSSLver="771" wSSLciph="TLS1.2-ECDHE-RSA-AES256-GCM-SHA384" wWsgClientIp="80.192.191.2" wFwdFor="-" wJlpLocation="-" wProtocol="HTTP/1.1" wUpstreamAddr="127.0.0.1:8080" wPort=443 s_vi="[CS]v1|2B4D4CA80501261B-600001064000B11D[CE]" s_ppv="jl%253Asearch%2C14%2C100%2C5789%2C414%2C628%2C414%2C736%2C3%2CP" recognisedUser="true" wUiCorrelationIdV1="-" wUserAgent="Mozilla/5.0 (iPhone;CPU iPhone OS 10_3_1 类似 Mac OS X)AppleWebKit/603.1.30 (KHTML, 像 Gecko) 版本/10.0 Mobile/14E304 Safari/602.1" deviceType="移动"
从以上两条日志,我们可以推断出jetty在2017-05-11T16:17:06.927Z返回了200响应,但是被nginx在2017-05-11T17:18:09+01:00接收到了。这 60 多秒导致超时。这有点奇怪,因为 nginx 和 jetty 都托管在同一主机上。
如果有人可以帮助我们调试问题或提供建议,那就太好了。
提前非常感谢。
【问题讨论】:
-
你能发布你的 NGINX 配置吗?失败有什么规律吗?它们是否发生在特定时间或特定类型的请求中?
-
感谢@FaisalMemon,已将
nginx.conf粘贴到pastebin.com/K5NxKah0 此处。这些超时以不规则的时间间隔发生,没有观察到任何模式。这只发生在GET请求中 -
另一个观察结果,在超时警报之前,我们看到下面的警报由 nginx 触发。
2017/05/11 06:41:51 [alert] 14485#14485: ignore long locked inactive cache entry 424b6374aeba3d9cc85ba5833e3163cd, count:1 -
上述问题已在github.com/FRiCKLE/ngx_slowfs_cache/issues/4 中讨论过,据说在
1.10版本中已修复。我们当前的 nginx 版本是1.11。尽管我们使用的是更高版本,但不确定为什么会出现上述错误。这可能是根本原因吗? -
能否请您发布处理请求的 nginx
location的配置?