线上服务由于缓冲区溢出造成的惨案 – Jack47

作者:Jack47

PS:如果喜欢我写的文章,欢迎关注我的微信公众账号程序员杰克,两边的文章会同步,也可以添加我的RSS订阅源

上周四上线新业务项目时,遇到了一系列非常诡异的问题,虽然最终得以顺利解决,但是整个过程非常曲折,暴露出的问题值得引起大家的思考,在此进行复盘,希望能够作为前车之鉴,大家从中吸取经验教训。

背景

简化的交互场景如下图,其中M是业务逻辑处理的节点,上面启动了程序m,D是存储展现数据的节点,上面启动了程序d,两个节点都是部署在不同的机器上的不同的服务。M会发送查询的请求给D,D查找到这些数据,进行简单的处理后,返回给M。

m_d

M与D的交互

本次新的业务项目,在D节点需要存储的数据中新增加了几个字段,这些数据都需要返回给M。

整个上线过程及出问题的过程如下:

功能测试通过后,进行了压力测试和稳定性测试,都没有发现问题,于是上线,预期节奏是上线实验环境,上线一个C机房,再上线另外一个机房E。上线实验环境后,以实验环境能接入的最大流量,占总流量的5%观察一天,没有出现任何问题,业务的各项指标也都正常。于是在第二天晚上上线一个机房,接流20%,第三天下午2点,这个机房流量扩大到50%,此时大部分M节点上,服务进程M的CPU占用率立马飙高,达到了80%左右!

现象

1. 一个机房M节点大部分的机器CPU飙高,达到80%

迅速将流量切走后,用gdb attach命令挂到m进程,发现都阻塞在从xdbm文件(是公司的小数据内存存储方案)获取数据的地方xdbm_fetch了。重启m进程后,现象依旧。用strace查看了一下此时M的系统调用,发现都阻塞在给一个xdbm文件用xlock(公司自己实现的锁)加锁的地方了,锁文件是“/tmp/.xlock/home/x/data/data_list.xdbm.rw”。

由于m自身只是读取xdbm数据,而数据data_list.xdbm是会有更新的,所以怀疑是线上进行xdbm文件更新时有问题,导致写锁没有释放,但是也没有直接的证据。这里分析了很长一段时间,从下午一直到晚上。即使删了这个目录下的所有锁文件,启动m后,依然会阻塞在这个地方。中间一度怀疑xdbm代码自身就有问题,尝试安装了不同版本的xlock的包,也没有解决问题。后来在不断尝试各种解决办法的时候,偶然发现进程列表里有一个xdbm_replace进程。它是用来更新整个xdbm数据内容的工具,它是需要创建文件写锁的!就是这里了,把这个进程kill掉,删除锁文件后,成功启动m!现在m虽然可以启动了,但是问题依然没有合理的解释:为什么这个锁被破坏了?

在开发同学查问题的同时,测试同学也在性能测试环境里复现问题,我们捞取了出问题那段时间附近10分钟的线上m服务的查询串,对整个系统进行了压力测试,可是没能复现问题。此时性能测试环境中的D节点是老的程序+数据,担心是这个原因导致不能复现,于是决定对D进行升级。

接下来我们调整了思路,仔细分析了发现的一个重要线索:这个锁文件里有业务的数据!而且每台机器上的内容都不完全一样,但可以肯定都是业务数据,而且这些数据都是D返回的。

这样就可以确定是M(这点很重要,排除了其他可能!)内部写内存越界,导致xdbm锁的数据内容被破坏。既然写入的是D数据,那就肯定是处理D数据的地方写入数据越界了。于是顺滕摸瓜,找到了最终要把这些数据输出到缓冲区的地方。由于本次D返回的数据字段变多,有好几个字符串类型的数据,可能导致输出时返回结果的长度变大。在看代码时发现有个数组的长度设置的有点小,很可能导致内存越界,于是迅速修改完这里的代码,然后上测试的性能环境验证。结果发现出问题了,程序会core,有core在给string赋空值的地方,也有core在new数组的地方!此时已经是晚上10点钟了。脑袋有点大了,后来觉得不对劲,又回过头仔细看了下这些业务数据,发现一些数据是图片地址,这些地址还是原始的地址,并没有拼接域名的头部,这就推翻了之前认为是拼接返回结果时写内存越界的可能性了,那就只能是另外一个地方了:M处理D返回结果的地方。

翻看代码,D返回数据是经过snappy压缩的,M需要先把数据解压缩后,再进行解析,解压缩使用的缓冲区长度为1M。接着发现这里代码逻辑有点问题,是先解压缩到缓冲区,再判断解压缩后的大小!这样就会有解压缩后缓冲区溢出的风险!修改完这里的代码,然后在性能环境上压测了1一个小时,没有出现问题!终于可以松口气了,xdbm锁被破坏的原因基本确定了,是因为M处理D返回结果时没有判断数据的大小,导致缓冲区溢出,正好是把存储xdbm锁信息的内存给破坏掉了。

此时已经是晚上2点多钟了,进行了M的上线。此时正在全链路压测,D上出现了一些ERROR日志:解析M发给D的数据时,D内部的一个缓冲区长度太小了,不能处理。看了一下代码,如果请求DN的Query中key的个数增多,超过正常的最大值200条,会有点问题,于是对其进行合理扩大。已经晚上4点了,太困了,准备睡一觉,上午来了回归测试完,上线D,修复这个问题。

2. B类请求出现问题,有大量的空结果

上午12点钟,将B类请求流量,接入到了C机房,以前一直是在还没有上线新功能的E机房。此时陆续就有客户反馈B功能不可用。拿出B类的请求串来看,发现M最终返回的数据集合是空的:

  1. 有一些请求串,M解析不了D返回的结果,说明D返回数据有问题
  2. 有一些请求串,D返回的数据集合为空

上D机器上去看系统运行日志,发现有很多ERROR日志:输出新增的imgUrl数据字段到缓冲区时,缓冲区大小不够了,因为这个字段的长度达到了几十K!正常最多也就百来字节,怎么会有这么大?

3. 有客户反馈扣费达到了1000元

祸不单行,在定位D原因时,传来了有些客户扣费达到1000元的消息。大周五的,咋出了这么多问题?反作弊同学反馈有些数据的点击串数据不正确,会触发保护策略,让实时反作弊系统发给结算的扣费价格变成1000元,此时客户的实时报表里,就看到点击扣费变成1000元了!拿到了这些有问题的PV日志,发现这些流量是从试验田出来的,于是赶紧切掉试验田的流量,问题消失,但此时已经影响到了上百个客户。此时试验田的M版本是没有修复问题1的老版本,在处理D返回结果时会有问题。所以问题肯定就是出在这里了,D返回结果变大,超过M的缓冲区大小,就会导致写内存越界,最终导致M中拼接的点击串有问题。此时是多么的希望程序能够直接core掉啊,core了至少能够有现场,而不是产生错误的数据,进而造成经济损失。

问题1和问题3同样都是缓冲区溢出的问题,现象却不一样。

继续排查问题2,D在B类请求下有问题,于是精力集中在D上。上文中提到过,D这里的ERROR日志里,都是在输出imgUrl字段的时候出错的。这里的逻辑是从数据里取出图片地址。B类请求的特点是请求的key很多,达到200个,是不是这两百个key里,有些key的数据很大?而我们处理每个key的数据时,缓冲区只有1K大小,很有可能是这里了。本次上线中,构建D的全量数据的过程也有重大调整,不能排除全量数据有问题的可能。每次B的流量来,都可以复现这个问题,于是直接到机器上去用gdb调试,在最终序列化这个字段的地方加断点,看数据到底长什么样子?

本来以为很快就能定位,结果半路又杀出个程咬金来:输出这个字段的地方,使用的是用宏定义的函数,函数内部用局部变量来获取imgUrl字段,然后输出到缓存里。导致gdb运行到这里,一次就过去了,啥都看不到。而且imgUrl的迭代器,也是用宏来写的,gdb里虽然能拿到指针,但看不到里面数据长啥样子。

在我这边确认具体原因的同时,测试修改了压力测试的Query,把里面跟key个数相关的参数都调整了一下,然后开始压力测试。发现问题可以复现了,太好了!我把D上扩大数据处理缓冲区的版本先交给了测试,进行压力测试验证,看看问题是否修复。但很快测试就发现问题依旧。此时已经到了晚上6点了,问题还是没有解决,系统工程师想要回滚我们的上线,但回滚代价很大,我们已经上了C机房了,就差E机房,如果回滚,将直接导致依赖我们上线的其他团队的本期项目也会延期发布。如果回滚,局面会非常被动。

一定要把这个bug揪出来!直接调试不行,那就看代码吧,肯定是这次改动的代码引入的,跟其他同事把这几段处理代码过了好几边,都没有发现问题。此时已经是晚上10点了,前天晚上熬夜,今天又连续很长时间查问题之后,大家的脑袋都有点僵了,此时又陷入了僵局。我去厕所洗了把脸,回来后跟另外一个同事讲了一下这里的业务逻辑。此时他提出了一个思路:既然肯定是这里的问题,那就把想要的信息都打印到日志里!Bingo,我咋没早想到这一点呢。于是上去加日志,发现DEBUG级别的日志里,基本信息都有了,于是直接开DEBUG日志。刷了一个请求,看了一下DEBUG日志,真相就大白了,在查询的key很多的情况下,候选的数据量达到了六百多个。刚刚看了很多遍imgUrl处理的地方,那里对处理的数据个数的限制是500个,那肯定就是处理时越界了!这样imgUrl字段的字符串结束符''被破坏,导致这个字段超长。扩大了这里的缓冲区大小,同时加上长度的保护和错误日志来修复。后续进行压测,确定问题已经解决了。

这个bug,其实跟去年的Open SSL心脏出血,是很类似的,都是对长度没有加以判断,导致写缓冲区出现问题。

经验教训

  1. 如果有core产生,需要注意看core的地方,如果发现指针所指的这片内存不能访问,那十有八九被写坏了。既然被写坏了,就可以通过分析写到这里的数据的特点,来找到写入这些数据,也就是发生缓冲区溢出的地方了。如果是这种查询类服务,本次查询的请求串非常重要,出core时可以看看到底是什么样的请求串,分析一下请求串的特点。
  2. 程序中同一个常量的定义,一定要用同一份,坚决不要散落在各个地方,不要在每个cpp中定义一份
  3. 不要有思维定势,认为在线上运行了很久的代码就一定不会出问题
  4. 对ERROR日志要足够重视,一查到底,否则后续很可能出问题,等到出问题再查,损失就大了,而且投入的人力成本会更高
  5. 考虑搞一些gdb的脚本,用来打印程序里关键的数据结构,比如M中的数据集合,通过这些关键数据来分析core的问题。目前M里的数据结构层级太深,用gdb打印内容非常不方便
  6. 尽量避免使用宏,如果非用不可,编译的时候,要把调试宏的选项打开:-gdwardf-2-g3
  7. 如果使用固定大小的缓冲区,那么在写入数据时,一定要做数据长度和缓冲区大小的判断,否则会导致写入溢出的数据!

最后,推荐一个很好的资料给大家,苹果公司的Secure Coding Guide


如果您看了本篇博客,觉得对您有所收获,请点击右下角的“推荐”,让更多人看到!

资助Jack47写作,打赏一个鸡蛋灌饼钱吧
pay_weixin
微信打赏
pay_alipay
支付宝打赏

本文链接:线上服务由于缓冲区溢出造成的惨案,转载请注明。



You must enable javascript to see captcha here!

Copyright © All Rights Reserved · Green Hope Theme by Sivan & schiy · Proudly powered by WordPress

无觅相关文章插件,快速提升流量