mysql响应时间超时排查

• 背景：

数据库运营环境，zabbix mysql响应时间告警，响应时间超时

• zabbix监控

• tcprstart 直接抓包响应时间看到每5秒钟就一次，与zabbix监控一致

[root@slave1(35.101) /r2/monitor]# tcprstat -l 192.168.3.101  -p 3306 -t 1 -n 0 
timestamp	count	max	min	avg	med	stddev	95_max	95_avg	95_std	99_max	99_avg	99_std
1540537920	0	0	0	0	0	0	0	0	0	0	0	0
1540537921	7	95	54	77	73	16	92	74	15	92	74	15
1540537922	0	0	0	0	0	0	0	0	0	0	0	0
1540537923	0	0	0	0	0	0	0	0	0	0	0	0
1540537924	0	0	0	0	0	0	0	0	0	0	0	0
1540537925	0	0	0	0	0	0	0	0	0	0	0	0
1540537926	0	0	0	0	0	0	0	0	0	0	0	0
1540537927	0	0	0	0	0	0	0	0	0	0	0	0
1540537928	1	5000198	5000198	5000198	5000198	0	0	0	0	0	0	0
1540537929	0	0	0	0	0	0	0	0	0	0	0	0
1540537930	0	0	0	0	0	0	0	0	0	0	0	0
1540537931	0	0	0	0	0	0	0	0	0	0	0	0
1540537932	0	0	0	0	0	0	0	0	0	0	0	0
1540537933	1	5000178	5000178	5000178	5000178	0	0	0	0	0	0	0
1540537934	0	0	0	0	0	0	0	0	0	0	0	0
1540537935	0	0	0	0	0	0	0	0	0	0	0	0
1540537936	0	0	0	0	0	0	0	0	0	0	0	0
1540537937	0	0	0	0	0	0	0	0	0	0	0	0
1540537938	1	5000162	5000162	5000162	5000162	0	0	0	0	0	0	0
1540537939	0	0	0	0	0	0	0	0	0	0	0	0
1540537940	0	0	0	0	0	0	0	0	0	0	0	0
1540537941	0	0	0	0	0	0	0	0	0	0	0	0
1540537942	0	0	0	0	0	0	0	0	0	0	0	0
1540537943	1	5000171	5000171	5000171	5000171	0	0	0	0	0	0	0
1540537944	0	0	0	0	0	0	0	0	0	0	0	0
1540537945	0	0	0	0	0	0	0	0	0	0	0	0
1540537946	0	0	0	0	0	0	0	0	0	0	0	0
1540537947	0	0	0	0	0	0	0	0	0	0	0	0
1540537948	1	5000192	5000192	5000192	5000192	0	0	0	0	0	0	0
1540537949	0	0	0	0	0	0	0	0	0	0	0	0
1540537950	0	0	0	0	0	0	0	0	0	0	0	0
1540537951	0	0	0	0	0	0	0	0	0	0	0	0
1540537952	0	0	0	0	0	0	0	0	0	0	0	0
1540537953	1	5000175	5000175	5000175	5000175	0	0	0	0	0	0	0
1540537954	0	0	0	0	0	0	0	0	0	0	0	0
1540537955	0	0	0	0	0	0	0	0	0	0	0	0
1540537956	0	0	0	0	0	0	0	0	0	0	0	0
1540537957	0	0	0	0	0	0	0	0	0	0	0	0
1540537958	1	5000186	5000186	5000186	5000186	0	0	0	0	0	0	0
1540537959	0	0	0	0	0	0	0	0	0	0	0	0
1540537960	0	0	0	0	0	0	0	0	0	0	0	0
1540537961	0	0	0	0	0	0	0	0	0	0	0	0
1540537962	0	0	0	0	0	0	0	0	0	0	0	0
1540537963	1	5000201	5000201	5000201	5000201	0	0	0	0	0	0	0
1540537964	0	0	0	0	0	0	0	0	0	0	0	0
1540537965	0	0	0	0	0	0	0	0	0	0	0	0
1540537966	0	0	0	0	0	0	0	0	0	0	0	0
1540537967	0	0	0	0	0	0	0	0	0	0	0	0
1540537968	1	5000146	5000146	5000146	5000146	0	0	0	0	0	0	0
1540537969	0	0	0	0	0	0	0	0	0	0	0	0
1540537970	0	0	0	0	0	0	0	0	0	0	0	0
1540537971	0	0	0	0	0	0	0	0	0	0	0	0
1540537972	0	0	0	0	0	0	0	0	0	0	0	0
1540537973	1	5000173	5000173	5000173	5000173	0	0	0	0	0	0	0
1540537974	0	0	0	0	0	0	0	0	0	0	0	0
1540537975	0	0	0	0	0	0	0	0	0	0	0	0
1540537976	0	0	0	0	0	0	0	0	0	0	0	0
1540537977	0	0	0	0	0	0	0	0	0	0	0	0
1540537978	1	5000229	5000229	5000229	5000229	0	0	0	0	0	0	0
1540537979	0	0	0	0	0	0	0	0	0	0	0	0
1540537980	0	0	0	0	0	0	0	0	0	0	0	0
1540537981	0	0	0	0	0	0	0	0	0	0	0	0
1540537982	0	0	0	0	0	0	0	0	0	0	0	0
1540537983	1	5000144	5000144	5000144	5000144	0	0	0	0	0	0	0
1540537984	0	0	0	0	0	0	0	0	0	0	0	0
1540537985	1	357	357	357	357	0	0	0	0	0	0	0
1540537986	0	0	0	0	0	0	0	0	0	0	0	0
1540537987	0	0	0	0	0	0	0	0	0	0	0	0
1540537988	1	5000196	5000196	5000196	5000196	0	0	0	0	0	0	0

• 通过tcpdump 抓包

[root@slave1(35.101) /r2/monitor]#  tcpdump -i em4 -s 3000 port 3306 -w  em4sql.pcap
tcpdump: listening on em4, link-type EN10MB (Ethernet), capture size 3000 bytes
^C576 packets captured
591 packets received by filter
0 packets dropped by kernel

• 使用wireshark 分析em4sql.pcap

可以看响应的时间

可以看到实际的sql