事故现场
昨晚0点起某系统多个监控指标报警,关键埋点调用量大幅下滑,小时级调用量同比昨日下滑到2%。
背景
该应用通过MQ消费多个数据源进行业务逻辑处理,结果写入关系数据库。
每日消费消息有数千万条。
上一次发版时间8月2日,期间无异常。
初步分析
早上上班后检查该应用所有埋点监控数据,发现所有埋点同比昨日仅有5%,且没有任何错误埋点。当时已经是早上八点半,今天已过三分之一,理论上各埋点同比应该在33%左右。该情况表明应用有问题,需要登录服务器检查。
在服务器上发现,该应用日志正常,CPU负载120%,占满一个核心。
初步判定,可能是代码有BUG,导致CPU飚高,影响业务处理。
此时其实有点疑问,如果业务处理变慢,星尘监控的埋点耗时应该变大,并且有些埋点跟业务处理无关,不应该数据下降那么多。
先来分析解决CPU飚高的问题,现在dotTrace命令行工具,在服务器上对应用进程抓30秒数据回来。
./dottrace attach 62777 --save-to=../segment.dtp --timeout=30s
把dtp包下载回来本地,dotTrace打开分析
貌似没有什么异常,每个调用都中规中矩。
至此,线索中断。
柳暗花明
早几天测试环境刚好遇到一个事情,星尘所在SQLite在凌晨1点左右,数据库锁住了,导致应用埋点监控异常。实际上是那段时间,所有监控数据都无法落库。导致我以为应用出问题。
生产环境的星尘跑在物理机MySql上,不会出现SQLite锁,但可能是别的问题。于是检查生产星尘StarServer的埋点监控,收获很大!
StarServer今天的错误数大幅上升,肯定是出问题了。点进去看今天的埋点情况,按照错误数排序。
查看小时级曲线
果然是0点开始出问题。点击错误数进去,如上图的233或338,挑选几个追踪进去看看。
看到有sql错误,鼠标移上去,看见了错误内容“Packets larger than max_allowed_packet are not allowed”
至此,算是发现了问题所在。
埋点监控的Tag标签数据过大,批量插入MySql时,超过了最大数据包大小,导致落库失败!
星尘中该数据是异步落库,所以并不会导致接口报错,因此也没有告警提示。
找到问题以后,解决起来就容易多了。在星尘监控的应用跟踪器中,修改一下标签大小参数即可。
该参数默认值是1024,上个月为了分析问题修改为4096.
当然,也可以修改mysql配置,加大最大包大小参数。
两三分钟后,告警应用各埋点指标迅速上升,恢复到正常水平!
追本溯源
星尘在7月份增加了一项新功能,支持数据分表后进行行级压缩,埋点表和采样表存储空间占用空间一下子降低到原来的30%。
目前星尘存储30天压缩数据,每天2000万左右,总占用660G。如果没有压缩,将要占用2T以上。
正是因为空间富裕了,为了方便查找问题,才加大标签大小。
目前的星尘工作很健康,IO上压力比较大,虽然解决了空间占用问题,但是目前mysql仍然有着平均每秒12M字节的写入速度。