【问题】大约每隔x秒会出现响应时间慢的问题

fightingshao

Hi all,

我是nginx小白，用openresty部署了一个简单的地址压缩服务，结果测试机轰炸后发现每隔一段时间，响应时间会变慢，这个问题迟迟不知道该如何troubleshoot，我尝试用网上的一些nginx performance tuning来调试，但是仍无果，所以想请假这里的大神们能给些指导，多谢！

原本使用了redis做缓存，后来怀疑是redis的问题，就索性直接返回一个假的，但是测试后还是会出现上面的情况。

测试用100台虚机，每台虚机上面放5个instance，然后连续curl服务1小时.

以下是配置详情：

服务器：

aws上CentOS Linux 7 x86_64 HVM EBS

2CPU，8G Memory

/etc/sysctl.conf

fs.file-max = 70000

net.core.somaxconn = 65536

net.core.netdev_max_backlog = 1024

net.ipv4.tcp_max_tw_buckets = 1440000

net.ipv4.ip_local_port_range = 1024 65000

net.ipv4.tcp_fin_timeout = 15

net.ipv4.tcp_window_scaling = 1

net.ipv4.tcp_max_syn_backlog = 3240000

nginx.conf(或见附件，这里有一个问题，就是我在access_log中希望能够记录下upstream的一些时间，但是这里都没有值,请问是为什么啊？):

log示例： 10/Feb/2017:16:31:33 +0800" client=52.80.3.92 method=GET request="GET /tracking_23901b9dc3 HTTP/1.1" request_length=100 status=302 bytes_sent=392 body_bytes_sent=167 referer=- user_agent="curl/7.47.1" upstream_addr=- upstream_status=-

request_time=0.000 upstream_response_time=- upstream_connect_time=- upstream_header_time=-

worker_processes 1;

worker_rlimit_nofile 30000;

events {

worker_connections 10000;

use epoll;

multi_accept on;

}

http {

keepalive_timeout 65;

keepalive_requests 100000;

sendfile on;

tcp_nopush on;

tcp_nodelay on;

client_body_buffer_size 128k;

client_max_body_size 10m;

client_header_buffer_size 1k;

large_client_header_buffers 4 4k;

output_buffers 1 32k;

postpone_output 1460;

client_header_timeout 3m;

client_body_timeout 3m;

send_timeout 3m;

open_file_cache max=1000 inactive=20s;

open_file_cache_valid 30s;

open_file_cache_min_uses 5;

open_file_cache_errors off;

ssl_session_cache shared:SSL:10m;

init_by_lua '

local cjson = require "cjson"

--require "resty.redis"

log_format timed_combined '"$time_local" client=$remote_addr '

'method=$request_method request="$request" '

'request_length=$request_length '

'status=$status bytes_sent=$bytes_sent '

'body_bytes_sent=$body_bytes_sent '

'referer=$http_referer '

'user_agent="$http_user_agent" '

'upstream_addr=$upstream_addr '

'upstream_status=$upstream_status '

'request_time=$request_time '

'upstream_response_time=$upstream_response_time '

'upstream_connect_time=$upstream_connect_time '

'upstream_header_time=$upstream_header_time';

access_log /usr/local/openresty/nginx/logs/nginx-access.log timed_combined;

server {

set $home_url 'http://t.annalect.com.cn:80/';

set $default_redirect_url 'http://www.baidu.com/';

#set $redis_host '127.0.0.1';

#set $redis_port 6379;

set $resp_body "";

listen 80;

location /nginx_status {

stub_status ;

}

location ~ ^/tracking_(.+) {

lua_need_request_body on;

body_filter_by_lua '

local resp_body = string.sub(ngx.arg[1], 1, 1000)

ngx.ctx.buffered = (ngx.ctx.buffered or"") .. resp_body

if ngx.arg[2] then

ngx.var.resp_body = ngx.ctx.buffered

end

content_by_lua '

--local redis = require "resty.redis"

--local redis = redis:new()

--redis:set_timeout(1000)

--redis:connect(ngx.var.redis_host, ngx.var.redis_port)

--local res, err = redis:get(ngx.var[1])

local res, err = "http://www.baidu.com"

if not res or res == ngx.null then

return ngx.redirect(ngx.var.default_redirect_url, ngx.HTTP_MOVED_TEMPORARILY)

end

ngx.redirect(res, ngx.HTTP_MOVED_TEMPORARILY)

}

响应时间（抽取了一台机器上的数据，发现time_connect的时间都很短，但是time_starttransfer就开始慢了）：

worker_processes 1;
worker_rlimit_nofile 30000;
events {
    worker_connections 10000;
    use epoll;
    multi_accept on;
}

http {

    keepalive_timeout 65;
    keepalive_requests 100000;
    sendfile         on;
    tcp_nopush       on;
    tcp_nodelay      on;

    client_body_buffer_size    128k;
    client_max_body_size       10m;
    client_header_buffer_size    1k;
    large_client_header_buffers  4 4k;
    output_buffers   1 32k;
    postpone_output  1460;

    client_header_timeout  3m;
    client_body_timeout    3m;
    send_timeout           3m;

    open_file_cache max=1000 inactive=20s;
    open_file_cache_valid 30s;
    open_file_cache_min_uses 5;
    open_file_cache_errors off;

    ssl_session_cache    shared:SSL:10m;

    init_by_lua '
        local cjson = require "cjson"
        --require "resty.redis"
    ';

    log_format timed_combined '"$time_local" client=$remote_addr '
               'method=$request_method request="$request" '
               'request_length=$request_length '
               'status=$status bytes_sent=$bytes_sent '
               'body_bytes_sent=$body_bytes_sent '
               'referer=$http_referer '
               'user_agent="$http_user_agent" '
               'upstream_addr=$upstream_addr '
               'upstream_status=$upstream_status '
               'request_time=$request_time '
               'upstream_response_time=$upstream_response_time '
               'upstream_connect_time=$upstream_connect_time '
               'upstream_header_time=$upstream_header_time';

    access_log /usr/local/openresty/nginx/logs/nginx-access.log timed_combined;

    server {
        set $home_url 'http://t.annalect.com.cn:80/';
        set $default_redirect_url 'http://www.baidu.com/';
        #set $redis_host '127.0.0.1';
        #set $redis_port 6379;

       set $resp_body "";

        listen 80;

        location /nginx_status {
          stub_status ;
        }

        location ~ ^/tracking_(.+) {

           lua_need_request_body on;
           body_filter_by_lua '
                        local resp_body = string.sub(ngx.arg[1], 1, 1000)
                        ngx.ctx.buffered = (ngx.ctx.buffered or"") .. resp_body
                        if ngx.arg[2] then
                                ngx.var.resp_body = ngx.ctx.buffered
                        end
          ';

            content_by_lua '
                --local redis = require "resty.redis"
                --local redis = redis:new()

                --redis:set_timeout(1000)
                --redis:connect(ngx.var.redis_host, ngx.var.redis_port)

                --local res, err = redis:get(ngx.var[1])
                local res, err = "http://www.baidu.com";

                if not res or res == ngx.null then
                    return ngx.redirect(ngx.var.default_redirect_url, ngx.HTTP_MOVED_TEMPORARILY)
                end

                ngx.redirect(res, ngx.HTTP_MOVED_TEMPORARILY)
            ';
        }
   }
}

fightingshao

发现响应时间的图片没有被贴上来，补一下图片：

响应时间（抽取了一台机器上的数据，发现time_connect的时间都很短，但是time_starttransfer就开始慢了）：

detailyang

Hello.

>测试用100台虚机，每台虚机上面放5个instance，然后连续curl服务1小时.

你的目标机有 100 台 VM，压力产生的机器具体是多少, 具体用什么方法产生压测？你先得确认压力机有足够大的压力没有达到瓶颈，另外 curl 的请求模型能产生多大的压力呢:D, 还有你的目标机器就 2u，你跑一个实例两个 worker 就足够了。

>nginx.conf(或见附件，这里有一个问题，就是我在access_log中希望能够记录下upstream的一些时间，但是这里都没有值,请问是为什么啊？

你的日志格式里引用的是 upstream 模块的变量，在你的条件下使用 request_time 即可，具体参考 nginx 官方文档 http://nginx.org/en/docs/varindex.html

在 2017年2月13日下午12:45，Yulin Shao <fight...@gmail.com>写道：

发现响应时间的图片没有被贴上来，补一下图片：
响应时间（抽取了一台机器上的数据，发现time_connect的时间都很短，但是time_starttransfer就开始慢了）：

--

fightingshao

谢谢回复！

>测试用100台虚机，每台虚机上面放5个instance，然后连续curl服务1小时.

之前尝试过用JMeter,当request到1000000条的时候单机就很容易死掉，所以在aws上面开了很多的肉鸡测试机，看肉鸡测试机的cpu使用情况啥的都还好，那么还有什么方法可以检测出肉鸡的压力阈值呢？

所以请问一下一般你们是怎么进行大的压力测试的呀？

另外在发生这种模式的时候，kernal_log以及error.log里面都没有记录什么错误信息提示，那这样能排除nginx没有达到瓶颈么？我看nginx那台机子，cpu最高的使用率只有20%左右。

还有一个我不是很懂的地方，就是用stub_status来监测nginx参数的时候：

Active connections: 2 
server accepts handled requests
 409874 409874 410614 
Reading: 0 Writing: 1 Waiting: 1

我用JMeter开100个Thread,loop 100次，为什么active connections每次看只有2或4这种个位数呢?

但是在JMeter的summary里面确是正常的，那怎么检测nginx每秒真正的处理量呢：

summary = 10000 in 00:00:20 = 506.7/s Avg: 90 Min: 57 Max: 9418 Err: 1 (0.01%)

Tidying up ... @ Mon Feb 20 13:30:29 CST 2017 (1487568629211)

在 2017年2月13日星期一 UTC+8下午5:37:20，detailyang写道：

Hello.

>测试用100台虚机，每台虚机上面放5个instance，然后连续curl服务1小时.

你的目标机有 100 台 VM，压力产生的机器具体是多少, 具体用什么方法产生压测？你先得确认压力机有足够大的压力没有达到瓶颈，另外 curl 的请求模型能产生多大的压力呢:D, 还有你的目标机器就 2u，你跑一个实例两个 worker 就足够了。

>nginx.conf(或见附件，这里有一个问题，就是我在access_log中希望能够记录下upstream的一些时间，但是这里都没有值,请问是为什么啊？

你的日志格式里引用的是 upstream 模块的变量，在你的条件下使用 request_time 即可，具体参考 nginx 官方文档 http://nginx.org/en/docs/varindex.html

在 2017年2月13日下午12:45，Yulin Shao <fighti...@gmail.com>写道：
发现响应时间的图片没有被贴上来，补一下图片：
响应时间（抽取了一台机器上的数据，发现time_connect的时间都很短，但是time_starttransfer就开始慢了）：

--