春哥您好,今天看了您的回复,我们查了更多的信息,在redis2模块finalize加了一行代码,目前问题看上去似乎解决了,但是不知道是否会有其他的连带影响。
您如有时间,能否拨冗帮忙看看我们查问题的方法对不对?
以及
在redis2 finalize中(ngx_http_redis2_finalize_request)设置if(rc>0)r->headers_out.status = rc;解决问题是否可行?
1.问题描述:[ngx_openresty-1.7.7.2版本 redis2-nginx-module-0.11]
问题504:upstream返回是504(超时),location返回是200(正常)
正常504:upstream返回504,location返回504
在多worker有压力条件下,nginx取redis出现问题504,出现频率很少,返回body只有一部分,但是state返回200,所以在解析json的时候失败。
2.找问题过程:
nginx按照debug方式编译,conf中打开debug选项,部分源码中添加日志打印信息
a.问题504报错:
http upstream process non buffered upstream
upstream timed out (110: Connection timed out) while reading
upstream,client:xx
正常504报错:
upstream timed out (110: Connection timed out) while reading response
header from upstream,client:xx
b.经过对redis2模块回调函数的跟踪,(bundle/redis2-nginx-module-0.11/src
/ngx_http_redis2_handler.c:79)
问题504和正常504:直接调用ngx_http_redis2_finalize_request,没调process
正常200:调用ngx_http_redis2_process_header,然后
ngx_http_redis2_finalize_request
问题504和正常504在报错后的行为路径不同:一个退出一个继续
在reading upstream报超时的时候直接执行了ngx_http_upstream_finalize_request
bundle/nginx-1.7.7/src/http/ngx_http_upstream.c:3014
ngx_http_upstream_finalize_request:3685调用了u->finalize_request(r,
rc),这个是模块的回调函数
而reading response header报超时的时候执行ngx_http_upstream_next
bundle/nginx-1.7.7/src/http/ngx_http_upstream.c:1791
c.在redis2回调函数finalize中打印确认各项state信息:
问题504:
upstream ret 504(这是回调传参信息,应该是upstream的返回)
r->upstream->state->status 200(这是location里面记录状态的信息)
r->headers_out.status 200(这是给外界返回信息)
正常504:
upstream ret 504
r->upstream->state->status 504
r->headers_out.status 0
尝试把问题504的upstream status修改为504,问题还是发生
d.ngx_http_upstream_finalize_request根据header_sent的值问题504和正常504
走了不同的路径:
问题504:header_sent:1
正常504:header_sent:0
if (!u->header_sent|| rc == NGX_HTTP_REQUEST_TIME_OUT|| rc ==
NGX_HTTP_CLIENT_CLOSED_REQUEST){something return;}
bundle/nginx-1.7.7/src/http/ngx_http_upstream.c:3792
尝试通过修改在redis2 finalize中header_sent为0让他们都走同一个路径,问题还是发生
e.因为我通过lua capture调用,经过寻找capture中相关状态的源码,打印
问题504:coctx->sr_statuses[index] 200
正常504:coctx->sr_statuses[index] 504
找到get这个数据的部分:
lua_pushinteger(co, coctx->sr_statuses[index]);
bundle/ngx_lua-0.9.14/src/ngx_http_lua_subrequest.c:
找到set这个数据的部分:
pr_coctx->sr_statuses[ctx->index] = r->headers_out.status;
因为这个问题504只回调了ngx_http_redis2_finalize_request
在redis2 finalize中设置if(ret>300)headers_out.status=ret;
问题不再复现
去掉之前两个修改,只保留这个,问题不再复现
Regard
On Wednesday, March 18, 2015 at 3:32:37 AM UTC+8, agentzh wrote:
Hello!
超时是一类比较复杂的错误,可能的原因很多,比如 redis-server 是性能瓶颈(哪怕是瞬时高并发的情况下),kernel 级别的
socket 协议栈的延时或包丢弃,或者 nginx 有东西较长时间地阻塞事件循环(无论是 off-CPU 的阻塞的系统调用,还是
on-CPU 的密集计算)。所以当你在报告超时相关的问题时,应当首先把自己的功课做足,先排除尽可能多的可能性,提供尽可能多的细节信息。把
read timeout 阈值设得很小,自然会超时,毕竟没有东西是 0 延时的。
Regards,
-agentzh