问题起因
“只开一个监视器的数据落库,怎么会导致网络带宽打满?这才多少数据,快查!”客户说
信息收集
首先咨询了在客户现场的支持人员确定了客户现场部署架构,双机房四个监控节点,其中只有一个出现问题,出现问题的节点的网络带宽比较小,只有20M
从客户现场监控系统对网络的监控图上来看,发送确实到达了20M,且持续不下。
理智告诉我不可能,一个监视器的传输到INFLUXDB的数据最多不会超过1M,事出反常必有妖,让我们开始这次的“捉妖记”。
排查过程
确定被打满的具体网卡
本例中因为有SEE的监控,可以直接从页面上获取到问题网卡em1。如果没有页面支持也可以使用sar命令来监控网卡,得到哪块网卡流量大一些,从而进行下面的逻辑。得到的结论是一致的,我们关注em1这块网卡即可。
监控em1网卡流量
通过监控图可以发现是流出数据打满,所以我们需要确定em1这个网卡的具体流量流向是哪里。我们可以使用iftop命令对流量进行实时监控
iftop -i em1 -P
-i参数可以指定具体监测的网卡,-P 可以显示端口号。
通过上图可以发现,这20M的写入数据基本上都是写到172.1.9.14这台机器的18086接口对应的服务上,而这个端口对应的服务就是时序数据库influxdb,所以可以判断问题是在监控节点往influxdb写入数据出的问题。
确定流量内容
要确定这20M的数据是什么,最好的方式就是网络抓包了。在有问题的监控节点上执行如下命令,抓取流向172.1.9.14机器18086端口的流量,具体参数含义可以从网络上搜索到。
tcpdump -i em1 -s 0 -nnA 'dst host 172.1.9.14 and port 18086'
将抓到的内容提取出来对内容进行分析,乍一看没看出端倪,都是业务数据。但是浏览过程中发现好像有些数据上面见过,就搜索了一下,发现确实存在相同的数据,且多达9处
代码跟踪
tcpdump的结果和事实不符。正常情况下,当采集节点往influxdb写入数据之后,会清理掉内存中的数据,防止下次重复插入,但是现在发现了很多重复的数据,那一定是代码逻辑出现了问题,于是找到写入influxdb的代码进行review,伪代码如下:
public void writePoints{
while(true){
List<Point> logPoints= logMapPoints.get();
try{
infludb.write(logPoints);
logPoints.clear();
}cache(Exception e){
}
}
}
代码逻辑如下:外层通过一个死循环,保证可以一直获取到Point的数据,随后调用Influxdb的API进行写入,写入成功后清理数据点。如果调用influxdb写入数据没问题还好,一旦发生异常,是不会清理数据点,而是继续循环调用。结合我们tcpdump拿到的数据来讲也是能对上的:装有相同数据的请求不只发送了一次,因为短时间内的多次重复调用导致写入数据量达到网卡阈值触发报警。如果我们推断是正确的话,那么调用influxdb.write方法应该是需要报错的。
问题验证
没有打印日志,我们怎么才能证明呢,我想到了arthas。因为想要看到和influxdb交互的最原始的信息,所以监控了Okhttp的相关方法,我们需要的是返回值returnObj,另外我们系统有很多和influxdb的交互请求,比如ping探活这种,为了更清晰的获取我们需要的数据,所以使用了ognl表达式对结果进行了过滤,我们只需要write方法的返回值即可。arthas具体参数含义可以从网络上搜索到,不再详述。
watch retrofit2.OkHttpCall execute 'returnObj' 'returnObj.rawResponse.request.url.url.path=="/write"' -x 2 -n 10
最终拿到了我们需要的结果:果然是写数据时报错了,报错的原因是influxdb数据库自我保护,设定每个标签对应的不同的值的数量最大为100000,超过这个值就写入失败,经过处理后功能恢复。
总结
本次事件是因为采集节点采集的部分数据超过influxdb设定的标签阈值而导致的写入失败,而后又引起了死循环调用将此错误数据重复投递导致带宽打满。留给我们的启示是做好服务之间的隔离,不要因为第三方服务的不可用导致自身服务出现故障,同时在日志打印和死循环逻辑的处理上有进一步优化的空间。
网友评论