我遇到了一个奇怪的问题,varnish 位于 API 前面,并且缓存了整个响应。它大部分时间都运行正常,但有时请求会比平时多花 5 秒(或很少 10 秒或 15 秒……总是以 5 秒为增量)才能返回。
我尝试绕过前面的 HAProxy,结果一样,我检查了一下,不管 URL 是否已经缓存,它都会这样做(我检查了 Age 标头)。所以问题不可能出在后端,因为页面在缓存中,问题不在于 varnish 前面的东西,所以问题只能出在 varnish 本身。
知道是什么原因导致了这 5 秒的延迟吗?我检查了 varnishlog,在延迟期间 varnish 没有执行任何操作。我还尝试在延迟期间手动发出另一个请求,varnish 响应良好,因此它没有冻结或出现其他问题,它工作正常。并且在 5 秒结束时,它会像往常一样输出请求的日志,其中没有任何奇怪的东西。示例:
- << 请求 >> 132712
- 开始请求 132711 rxreq
- 时间戳开始:1499701302.309413 0.000000 0.000000
- 时间戳请求:1499701302.309413 0.000000 0.000000
- 请求启动 127.0.0.1 43955
- 请求方法 GET
- 请求URL /url
- 请求协议 HTTP/1.1
- ReqHeader 用户代理: curl/7.38.0
- ReqHeader Host:主机
- ReqHeader 接受:/
- ReqHeader X-Forwarded-Proto: https
- ReqHeader X-Forwarded-For: ip
- ReqHeader 连接:关闭
- ReqUnset X-Forwarded-For: ip
- ReqHeader X-Forwarded-For: ip, 127.0.0.1
- VCL_call 接收
- ReqUnset X-Forwarded-For: ip, 127.0.0.1
- ReqHeader X-Forwarded-For: ip, 127.0.0.1, 127.0.0.1
- VCL_return 哈希
- VCL_call 哈希
- VCL_return 查找
- 点击 2147582482
- VCL_call 命中
- VCL_return 交付
- 响应协议 HTTP/1.1
- 响应状态 200
- 响应原因 OK
- 回复标题日期:2017 年 7 月 10 日星期一 15:10:00 GMT
- RespHeader 服务器: gunicorn/19.7.1
- RespHeader 内容类型:application/json;charset=UTF-8
- RespHeader X-Varnish:132712 98834
- RespHeader 年龄:1902
- RespHeader Via: 1.1 varnish-v4
- VCL_call 交付
- RespHeader X-Cacheable:是
- RespUnset 服务器: gunicorn/19.7.1
- RespUnset 通过: 1.1 varnish-v4
- RespUnset X-Varnish:132712 98834
- VCL_return 交付
- 时间戳进程:1499701302.309480 0.000067 0.000067
- RespHeader 内容长度:251799
- 调试“RES_MODE 2”
- RespHeader 连接:关闭
- RespHeader 接受范围:字节
- 时间戳响应:1499701302.309571 0.000159 0.000092
- 调试“XXX REF 2”
- 请求帐户 198 0 198 197 251799 251996
- 结尾
我知道 varnish 认为处理得很快,但在 curl 方面却花了 5 秒钟。curl 直接在 varnish 服务器上使用,因此这不是网络延迟。这有点难以重现,我使用了一个脚本,该脚本循环执行查询并显示 curl time_total 以最终实现它。
可能是 Linux 方面的问题吗?可能是某种限制,或者是套接字清理作业,或者是暂停请求的某些东西。这种情况可能每 400 或 500 个请求发生一次,有时多一些,有时少一些。
答案1
问题出在 DNS 解析上,curl 每次都会执行新的 DNS 查询,看起来这个服务器的解析器(Google 的 8.8.8.8)有时需要 5 秒钟才能回答。与 varnish 无关,是我的错