通过tcpdump和wireshark分析应用慢请求问题
最近通过报警发现应用频繁有超过1s的慢请求,通过查看日志、tcpudmp和wireshark最后定位是网络问题,在排查过程中也参考了网上的很多文章,但是写的都不是全,现在有空分享一下问题排查的一些经验,希望对遇到类似问题的码农们有所帮助,具体排查步骤如下:
- 查看程序日志,程序中对超过100ms的请求都有日志输出,通过查看日志发现有大量的数据库和redis超时
- 查看redis的慢请求,redis并没有发现慢请求日志,redis慢请求查看的方法具体可以参考redis的文档:http://doc.redisfans.com/server/slowlog.html
- 查看数据库的慢查询日志,数据库也没有相应的慢请求
- 最后开始怀疑时间是耗费在连接数据库和redis的网络连接上,通过tcpdump命令dump出系统上一定时间的tcp请求,具体命令是
tcpdump -i eth0 -s 0 -w tcp_245.pcap host 192.168.1.245
其中-i参数指定抓取哪个网卡上的tcp请求,-w参数指定dump的文件目录 host参数指定抓取该ip发出和收到的请求,-s 0 : 抓取数据包时默认抓取长度为68字节。加上-s 0 后可以抓到完整的数据包,具体其它命令参数可以通过tcpdump --help查看 - 通过wireshark分析dump出来的tcp请求,首先需要在wireshark中找到想要的请求,这时需要通过IP和端口号先过滤出所有的redis请求,具体截图如下:
其中ip.dst == 10.10.1.1 指定了redis所在的服务器ip, tcp.dstport == 7522指定了redis的端口号,过滤后明显发现有TCP Retransmission,即网络重传 - 为了确认是因为重传带来的时间损耗,需要过滤该次请求的完整记录,具体步骤:选择RetransmissionI的行--右键--选择追踪流--TCP流,截图如下:
从图中可以看出重传的tcp包中的seq和ack跟上面tcp包中的seq和ack是完全相同,数据包的大小也完全一样,可以确认是同一个tcp请求发生了一次重试,但是从时间上看延迟了200ms,这只是其中的一个TCP请求,如果一个HTTP请求中会有10个左右的数据库和redis请求延迟时间会达到2s以上。
相关推荐
gaogaorimu 2019-12-06
dreamnow0 2019-08-03
sapliang 2020-04-14
84251449 2019-12-26
周海汉的开发 2012-11-10
andyzhaojianhui 2011-03-05
nuligannima 2010-09-04
yuhuqiao 2010-08-17
ftafta 2010-08-17
Jungzhang 2010-03-03
Freshairx 2019-07-01
libra0 2019-06-29
jingz 2019-06-28
阳光之吻 2019-06-27
lfjjia 2016-04-05
DBwater 2014-08-06
想 2014-07-02
如竹 2013-05-14
西狂杨过 2013-02-07