记一次线上流量异常问题的排查

情景

通过zabbix监控发现有一个应用(service)和数据库(DB)之间存在不定时的流量异常(也不频繁),具体为应用server的入向流量和数据库server的出向流量会有短时间(通常在一分钟左右)的激增,甚至快达到千兆网卡的传输上限。

分析过程

通过症状,几乎可以断定是由于某些sql语句需要返回大量数据导致。但这次问题的分析结果确是很不顺利(其中有我前期方法不当的原因)。

初次分析:因为在那之前做了一个针对于故障/异常分析的日志分析系统(详见),并且基于此完成了两次异常uri的定位为题。所以惯性思维还是用这套东西来对流量异常时间段内出现的请求,按照出现次数或响应时间或者响应大小排序,观察。折腾了一通,然这个方法就不是分析这个问题最直接的方法,自然分析不出啥结果。
在这期间也想到了tcpdump抓包,但是有两个问题:因为异常时间不固定;不合适的方法会导致抓包产生的文件体积非常大。当时也没相处好方法来抓包,所以就没再深究这个想法。

再次分析:仔细想还是抓包才是最直接的方法。于是写了一个脚本,在应用server上每隔5s计算一下之前5s的入向流量的带宽,根据应用和数据库之间正常的流量设置一个阈值,超过次阈值则触发抓包动作。这次是能看到一部分异常的流量了,但是由于这个脚本的机制是先判断流量再触发抓包,所以先天缺陷是无法抓到引发流量异常的sql的。

最终分析,大脑经过一夜的后台运行,终于想到了一个“完美”的抓包方法,大致思路如下:

开始抓包,通过tcpdump的-w 参数将结果写到文件。然后在死循环里每隔5s计算一下前5s的平均流量,跟阈值相比:
如果小于阈值,则kill掉之前的tcpdump进行,重新开始一个tcpdump,抓包数据还写到先前的文件中(会覆盖掉之前内容,解决了抓包文件不断变大的问题);
如果大于阈值,则继续抓包,下一次循环再检测流量,若下一个5s周期流量降到了阈值之内,则kill掉tcpdump进程,同时将抓包文件重命名(这个是可以用来分析的有效抓包数据),然后再开启新的tcpdump重复之前的动作。

要点就是:既能抓住异常流量,又不至于抓包文件过大

话不多说,上脚本(这个脚本是整个过程的关键)

#!/bin/sh
#by ljk 2019/03/18
#对于不定期出现的网络流量异常进行合理抓包

file=/proc/net/dev
i=0    #用来标记是否出现了流量异常以及异常持续了几个检测周期
cd /usr/local/src/mysql-sniffer/logs/query/
alias capture='tcpdump -nnvv port 3306 -w tcpdump.txt &>/dev/null'

(capture) &    #放到后台执行,不至于阻塞主进程的逻辑

while true;do
    RX_bytes=`cat $file|grep eth0|sed 's/^ *//g'|awk -F'[ :]+' '{print $2}'`
    sleep 10    #间隔10s
    RX_bytes_later=`cat $file|grep eth0|sed 's/^ *//g'|awk -F'[ :]+' '{print $2}'`
    speed_RX=`echo "scale=0;($RX_bytes_later - $RX_bytes)*8/1024/1024/10"|bc`

    tcpdump_pid=`ps -ef|grep tcpdump|grep -v grep|awk '{print $2}'`

    if [ $speed_RX -lt 15 ];then    #我的阈值是15Mb
        kill -9 $tcpdump_pid
        if [ $i -gt 0 ];then
            mv tcpdump.txt "$i"_tcpdump_`date  +"%F_%H:%M:%S"`
        fi
        
        (capture) &
        i=0
    else
        i=$(($i+1))
    fi
done

把该脚本放到后台运行,然后我很轻松的抓取到了一次异常周期内的数据包,然后通过wireshark进行分析,也很快的找到了问题sql,不出所料,就是因为对用户输入的验证不够严谨,导致where条件里出现了空字串进而需要返回将近全表的数据(真坑)。

上一篇:tcpdump/grep/sed/awk/vi简单命令


下一篇:秉承开源精神, Datafuse Labs 会议室对外开放预定