一次 HTTPRequest TimeOut 分析

现象:访问产品间歇性出现TimeOut

现象:访问其他网站正常,但是只要是访问公司的产品网站有时就会非常缓慢,有时候会出现504 网关超时。 这种现象也是间歇性发生

收集基础信息

所有产品对外的nginx 出口机是10.9.171.123,外网IP是123.59.83.77

以下以:www.clickhouse.com.cn (clickhouse也是配置在ucloud 上) 为例进行分析:

1
2
curl www.clickhouse.com.cn -o /dev/null
curl www.clickhouse.com.cn -o /dev/null -x 10.9.171.123:80

分析请求过程中各个阶段所耗时间

参考使用 curl 命令分析请求的耗时情况

vim curl-format.txt,输入:

1
2
3
4
5
6
7
8
time_namelookup: %{time_namelookup}\n
time_connect: %{time_connect}\n
time_appconnect: %{time_appconnect}\n
time_redirect: %{time_redirect}\n
time_pretransfer: %{time_pretransfer}\n
time_starttransfer: %{time_starttransfer}\n
----------\n
time_total: %{time_total}\n

走内网地址:

1
curl -w "@curl-format.txt" -o /dev/null -s -L "http://www.clickhouse.com.cn" -x 10.9.171.123:80

得到结果分析

1
2
3
4
5
6
7
8
time_namelookup: 0.004169
time_connect: 0.039059
time_appconnect: 0.000000
time_redirect: 0.000000
time_pretransfer: 0.039177
time_starttransfer: 0.291800
----------
time_total: 0.397713
  • DNS 查询: 4.1ms
  • TCP 连接时间:pretransfter(39) - namelookup(4) = 35ms
  • SSL 处理时间(https):time_appconnect - time_connect
  • 重定向时间: starttransfer - time_pretransfer
  • 服务器处理时间:starttransfter(291) - pretransfer(39) = 252ms
  • 内容传输时间:total(397) - starttransfer(291) = 106ms

走外网地址:

1
curl -w "@curl-format.txt" -o /dev/null -s -L "http://www.clickhouse.com.cn"

结果分析:

1
2
3
4
5
6
7
8
time_namelookup: 0.004177
time_connect: 67.551252
time_appconnect: 0.000000
time_redirect: 0.000000
time_pretransfer: 67.551386
time_starttransfer: 67.790645
----------
time_total: 68.135138

结论

png_2

可以发现走外网ip, TCP 连接时间 所耗时间达到了68秒,但这个问题并不是持续出现,偶尔又非常快

png_3

方式二,httpstat统计工具

参考httpstat

安装 httpstat

1
2
3
pip install httpstat
# 或者
brew install httpstat

使用:

1
httpstat www.clickhouse.com.cn

png_5

nginx 状态检测

1.启用nginx status配置

1
2
3
4
5
6
7
8
9
10
11
server {
listen *:80 default_server;
server_name _;
location /ngx_status
{
stub_status on;
access_log off;
#allow 127.0.0.1;
#deny all;
}
}

2.重启nginx

1
2
/data/nginx/sbin/nginx -t
/data/nginx/sbin/nginx -s reload

3.打开status页面
执行:

1
curl http://10.9.171.123/ngx_status -H "HOST: localhost

结果:

1
2
3
4
Active connections: 834
server accepts handled requests
21613286 21613286 49361716
Reading: 0 Writing: 197 Waiting: 653
  • active connections – 活跃的连接数量
  • server accepts handled requests — 总共处理了21613286个连接 , 成功创建21613286次握手, 总共处理了49361716个请求
  • reading — 读取客户端的连接数.
  • writing — 响应数据到客户端的数量
  • waiting — 开启 keep-alive 的情况下,这个值等于 active – (reading+writing), 意思就是 Nginx 已经处理完正在等候下一次请求指令的驻留连接

活跃连接数才800多,远没有超负荷运行

路由跟踪

1
2
traceroute -m 15 -p 6888 10.9.171.123
traceroute -m 15 -p 6888 123.59.83.77

png_7

Traceroute能够显示到达目的地址所需的跳数、经过的路由器的IP地址、延时、丢包情况等信息。第一跳为10.10.0.1,第二跳为218.76.1.129,第三跳为xxxx;每条记录输出3个延时结果(源地址每次默认发送三个数据包);在第9条记录只有2个延时结果,说明源地址只收到了2个ICMP超时通知消息。

跨机房请求

png_8

网站简单性能测试

如果步骤一中,服务器处理时间 耗时较长,可以试试用 ab命令做下简单压测

参考http://man.linuxde.net/ab

1
2
3
ab -c 200 -n 1000 http://www.clickhouse.com.cn/
ab -c 200 -n 1000 http://www.clickhouse.com.cn/topic/5a4e08712141c291748355c2

png_6

坚持原创技术分享,您的支持将鼓励我继续创作!
分享