Chinaunix首页 | 论坛 | 博客
  • 博客访问: 1853021
  • 博文数量: 274
  • 博客积分: 2366
  • 博客等级: 大尉
  • 技术积分: 1880
  • 用 户 组: 普通用户
  • 注册时间: 2007-04-22 09:37
文章分类

全部博文(274)

文章存档

2022年(1)

2020年(10)

2019年(7)

2018年(18)

2017年(26)

2016年(32)

2015年(43)

2014年(30)

2013年(44)

2012年(36)

2011年(17)

2010年(10)

分类: LINUX

2013-01-30 11:36:36

问题表象:
一个机房上布了nginx+下载svr
从另外一个机房一台机器上wget下载某1.2G大小文件,一般情况下,速度都可以稳定的保持在10M-20M左右;
但有时wget,速度只能达到100K-150K左右,且这个速度一直提升不了,也是出奇的稳定;
现象补充:
问题很奇怪,于是尝试从其他机器去wget,发现很正常,不会出现这种问题;奇怪了!!!

问题分析:
感觉非常奇怪,速度相差非常远,但都比较稳定,一个是稳定的快,一个稳定的慢;
流程还是有点长,wget <-> nginx <-> 下载svr <-> 存储集群
初步分析任务 wget 和 nginx 之间应该不会有什么问题,应该比较相信他们;
第一反应是下载svr或者存储集群哪里有问题,最常见的是内部存储集群延迟厉害;


一步一步来吧:
1,先分析wget,strace 了下wget:
工具:strace, lsof, netstat
select(5, [4], NULL, NULL, {0, 950000}) = 1 (in [4], left {0, 930000})
read(4, "\260h ~\345\342\203\342\307\10"..., 16384) = 2896
clock_gettime(CLOCK_MONOTONIC, {11913187, 895767462}) = 0
write(3, "\260h ~\345\342\203\342"..., 2896) = 2896
select(5, [4], NULL, NULL, {0, 950000}) = 1 (in [4], left {0, 950000})
read(4, "\332\211d\322\37\27\350:"..., 16384) = 5792

wget 用了一个连接和nginx交互,但采用了select来做监控fd
在速度慢的情况下,strace过程中,select 会阻塞一小段时间,
虽然比较短,但肉眼能明显感觉的到这一阻塞,这是和现象相符的;
拿到这个tcp连接,netstat 下
tcp        0      0 test_cl:45101        nginx_dl:80           ESTABLISHED
果然,Recv-Q 和 Send-Q 都是空的;

结论:wget 是正常的;

2,再来分析nginx
工具:netstat
低速情况下,连续的 netstat 这个tcp连接结果如下:
tcp        0  94120 nginx_dl:80           test_cl:45101        ESTABLISHED
tcp        0  62264 nginx_dl:80           test_cl:45101        ESTABLISHED
tcp        0 102808 nginx_dl:80           test_cl:45101        ESTABLISHED 
tcp        0  79640 nginx_dl:80           test_cl:45101        ESTABLISHED 
tcp        0  82536 nginx_dl:80           test_cl:45101        ESTABLISHED 
tcp        0 102808 nginx_dl:80           test_cl:45101        ESTABLISHED 
tcp        0  92672 nginx_dl:80           test_cl:45101        ESTABLISHED

出乎我的意料,Send-Q 一直是大于0的一个值,明显,nginx这边的数据堆积在 tcp SendBuf 里面了;
wget接收too slow?但 wget 那边的 Recv-Q 一直是空啊;

VS:于是和高速度的情况下做个对比,netstat 结果如下:
tcp        0 1434149 nginx_dl:80           test_cl:41554        ESTABLISHED 
tcp        0 523928 nginx_dl:80           test_cl:41554        ESTABLISHED
tcp        0      0 nginx_dl:80           test_cl:41554        ESTABLISHED
tcp        0 558592 nginx_dl:80           test_cl:41554        ESTABLISHED
tcp        0      0 nginx_dl:80           test_cl:41554        ESTABLISHED 
tcp        0      0 nginx_dl:80           test_cl:41554        ESTABLISHED 
tcp        0 1572864 nginx_dl:80           test_cl:41554        ESTABLISHED 
Send-Q 缓冲中数据变化非常大,最大有1.2M左右(nginx的缓冲大小设置的比较大),
最低是0,而且有一半情况下是0;这个是和高速现象符合的;
对比两种情况下,最大区别是 Send-Q 中的数据大小;
同样的机器,同样的程序,为什么表现这么大区别?
结论:突然一个念头一闪,会不会是两种情况下tcp连接窗口大小相差太远造成的;

3,验证猜想:抓窗口大小
工具:tcpdump
高速情况下,tcpdump 输出三次握手的交互包:
14:08:13.088635 IP test_cl.57217 > nginx_dl.http: S 2882002423:2882002423(0) 
win 5840
14:08:19.121903 IP nginx_dl.http > test_cl.57217: S 162476119:162476119(0) 
ack 2882002424 win 5792
低速情况下,tcpdump 输出三次握手的交互包:
14:04:17.882002 IP test_cl.39735 > nginx_dl.http: S 2626073064:2626073064(0) 
win 5840
14:04:23.914918 IP nginx_dl.http > test_cl.39735: S 4202563613:4202563613(0) 
ack 2626073065 win 5792
 
呃,一样的,猜想失败!!
4,只能分析 tcpdump 的抓包了...
汗,tcpdump 后面包的 win 大小真有点看不懂啊!!!
看了好久才看明白,真正的窗口大小是:win*(2<
tcp有个慢启动的算法,窗口会比较小,然后慢慢增大;
低速情况下,tcpdump 窗口最后稳定在 501*(2<<7) = 60k 左右;
而高速情况下,tcpdump 窗口最后稳定在 24576*(2<<7) = 3M 左右;
另外在一台限速过的机器上进行下载,速度只能在40K左右,
tcpdump 窗口最后稳定在 5521*(2<<7) = 600k 左右;
5,很想准确的知道这个缓冲区大小到底多少,于是尝试用以前一个办法获取缓存区大小;
工具:gdb,netstat
低速情况下,gdb 挂住 wget
netstat 发现最后稳定在:
nginx :tcp        0  45184 nginx_dl:80           test_cl:41750        ESTABLISHED
wget  :tcp   189136      0 test_cl:41750        nginx_dl:80           ESTABLISHED
高速情况下,gdb 挂住 wget
nginx :tcp        0 3558289 nginx_dl:80           test_cl:46488        FIN_WAIT1
wget  :tcp   3759098      0 test_cl:46488        nginx_dl:80           ESTABLISHED
结论:明显低速情况下的wget接收缓冲远远小于高速情况下的接收缓冲大小!!
 基本和步骤4得到的结论差不多,也印证了这一结论;
6,搞了好久,还是没明白为什么,开始有点怀疑是后端svr的问题;
呃,突然想起,如果单独测试 wget+nginx 怎么样?会不会也出现这种问题,
于是在nginx目录下放了个1.2G的文件,然后wget;
速度那是杠杠的快啊,50-60M,试了10多次,都没任何问题,信心动摇了;
侥幸的心理驱使不停的按下去,突然,出现了个 200k 就不动了,最后稳定在了 135K 左右;
终于再次且肯定确定的排除了业务svr的问题;
是网络环境或者是机器的问题;
这种问题,按以往的做法,直接丢给运维...
呃,都搞了一下午,那就接着搞吧,不是业务svr的问题,也算是个问题吧,
先尝试怎么发现这个问题吧,虽然心理没底;
tcpdump 发现窗口最后稳定在 829*(2<<7) = 100k 左右;
7,仔细分析对比高速和低速下的 tcpdump 输出,差别在于:
低速的状况下,多了下面的一些包:
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
nginx_dl.http > test_cl.59114: . 6087:7535(1448) ack 477 win 54
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
test_cl.59114 > nginx_dl.http: . ack 6087 win 145
nginx_dl.http > test_cl.59114: . 6087:7535(1448) ack 477 win 54
另外,包里面还有些类似这样的重复 ack;
test_cl.59114 > nginx_dl.http: . ack 618591 win 501
test_cl.59114 > nginx_dl.http: . ack 618591 win 501
test_cl.59114 > nginx_dl.http: . ack 618591 win 501
test_cl.59114 > nginx_dl.http: . ack 618591 win 501
nginx_dl.http > test_cl.59114: . 618591:620039(1448) ack 477 win 54
test_cl.59114 > nginx_dl.http: . ack 618591 win 501
tcp的慢启动和拥塞算法里面有这样一段机制:
“由于我们不知道一个重复的ACK是由一个丢失的报文段引起的,还是由于仅仅出现了几个报文段的重新排序,
因此我们等待少量重复的ACK到来。假如这只是一些报文段的重新排序,则在重新排序的报文段被处理并产生
一个新的ACK之前,只可能产生1 ~ 2个重复的ACK。如果一连串收到3个或3个以上的重复ACK,就非常可能是
一个报文段丢失了。于是我们就重传丢失的数据报文段,而无需等待超时定时器溢出。这就是快速重传算法。
接下来执行的不是慢启动算法而是拥塞避免算法。这就是快速恢复算法。”
对比抓包输出,知道:
6087-7535 这一段数据,接收方(即wget程序)没收到,但却收到了后面一些包
发送方(即nginx)连续收到了3个这样的ack,知道包应该是丟了,于是立即重发 6087-7535 这段数据(即第四行)
但是又连续连续7个ack过来,于是nginx再次重发这段数据;
因为丢失了包,于是慢启动被中止了,进入了拥塞避免算法...
对后面的log进行分析,发现这样的情况时断时止,导致窗口根本上不去;


问题终于发现了:
client本身系统或者中间的路由有问题,导致tcp包有很多都乱了(也有可能是真的丢了)
但奇怪的是这种丢包仅仅针对已经建立的tcp连接;

BTW:数据流服务器真的挺需要依赖 tcp 性能分析以及优化的,包括上传,下载等等...


阅读(1735) | 评论(0) | 转发(0) |
给主人留下些什么吧!~~