写点什么

意想不到,这个神奇的 bug 让我加班到深夜

发布于: 2021 年 01 月 02 日
意想不到,这个神奇的bug让我加班到深夜

给大家分享一个近期解决的线上问题,起因是这样的,近期参与公司的一个项目,工程量很大,代码编写测试过后终于到了紧张的上线时刻。


项目上线


上线前照例忐忑不安了一番,因为工程量比较大,预估可能不会很顺利,但还不至于到了祈祷服务器不要出 bug 的地步,bug 对于程序员来说简直是家常便饭,没有 bug 反而可能会嘀咕半天,这都是职业病,没治。


紧张了一会儿,我屏气凝神,点了上线按钮,那一刻简直就像在点核按钮一样,生怕点下去后服务器会轰的一声炸掉。



结果一切正常。。。


这不对啊,这时博主的职业病又犯了,这么大的改动不会这么顺利吧,内存、CPU、tp99 耗时一切正常,这太不正常了吧。


说曹操曹操就到


就在博主想为什么没有 bug 时,bug 简直就像听到了我的召唤一样如约而至,博主当时甚至在想为什么梦想中的 500 万彩票就这么不听话呢?


(bug 妹妹:“程序员哥哥,我来啦”;


500 万妹妹:“不,程序员哥哥,不要说门,窗户都没有。。。”)


上线最初一切正常,问题就出在了接下来的一段时间里。


在接下来的时间里,tp99 耗时就像通货膨胀一样不可遏制的一路上扬,线上收入就像股市一样不可遏制的一路重挫。



这时博主的内心反而踏实了很多,没错,就是这个味儿,还是熟悉的配方还是熟悉的味道,I know it。


废话少说,赶紧回滚,线上恢复正常后接下来就是问题排查了。


排查问题


从监控上看,一次请求的处理时间会越来越高,那么显然问题的关键就是定位耗时出现在了哪段代码上。


没有办法,只能一点一点的去找监控了,幸好代码中监控比较丰富,一番梳理后最终锁定在了这样一行代码:


// 监控代码
复制代码


obj a = b;
复制代码


// 监控代码
复制代码

这段代码本质上是在干什么呢?很简单,就是对象的 copy,而且在我们的实现中还是浅 copy,也就是仅仅 copy 了一些字段。


从监控看就是这行代码导致了 tp99 耗时不断上涨。


这。。这怎么可能呢?简简单单的一个对象拷贝竟然会让耗时上涨那么多,而且还是随着时间缓慢上涨,这也太神奇了吧。



当人遇到自己不能理解的问题时通常会归因于外部因素,博主也不能免俗。


接下来就是怀疑人生的时刻。


不会是监控有问题吧,不会是编译器的原因吧,不会是硬件的原因吧,不会是天气的原因的吧,总之不是我的原因。



一番思索后最终理性战胜了自己,哪有那么多原因,在没有其它证据下目前看就是这个对象拷贝导致的。


那么为什么一个简单的对象拷贝会导致 CPU 消耗越来越高,耗时越涨越多呢?


这里的关键在于意识到这一点,既然随着时间的推移耗时会越来越高,那么很显然是某个全局性质的数据随着请求的处理越堆积越多,而出问题的这个对象使用到了这个全局数据。没错,就是这样,终于要见到曙光啦,哈哈,激动!



这就解释了为什么这个对象随着时间的推移就和美债一样越滚越多,变得越来越庞大了,虽然美国政府可能没打算还美债,但是 CPU 拷贝越来越多的数据必然导致耗时越来越高。


找出 bug


既然明确了方向,接下来就有针对性了。


首先去看一下这个对象都有哪些成员变量,对于内置类型像 int、bool 之类肯定不会有问题,因为这些类型的变量大小是固定的,需要注意的就是这种 vector、set 之类的容器。


最终经过一番检查后断定问题就是出在了某个 vector 成员变量上,同时也验证了上述猜想。


真相大白


问题是这样的。


这个对象的某个 vector 成员变量每次在处理请求时都要用另一个对象(假设为对象 A)的数据来进行初始化,就像这样:



在每次处理一个请求之前,A 持有的 Data 都会被 push 一些特定的数据。


而系统为了优化内存分配开销,对象 A 被放到了内存池中,就像这样:



由于对象被放到了内存池,因此对象 A 是不会被释放的,这就让对象 A 无形中变为了全局性质的对象


现在,有的同学可能已经发现问题了,那就是,如果对象 A 在放回内存池后没有清空持有的 Data,那么就会导致这样的一个问题,那就是 A 持有的 Data 随着每个请求的到来不断的被 push 数据,这就会导致 A 持有的 Data 就像泡沫一样越吹越大,相应的 Obj 对象持有的 vector 也会越来越大:



在这种情况下拷贝 Obj 对象必然要拷贝持有的 vector,由于 vector 越来越大,因此消耗在拷贝上的时间也越来越多,使用内存池本意是好的,但由于使用完后忘记清理其保存的旧数据反而造成了内存泄漏


经验教训


这次的问题从代码编写角度看是这样的,对象 A 中 Data 字段的清理工作没有放在对象 A 的 Clear 函数,反而要靠使用者自己清理,由于代码非常复杂极其容易疏漏,博主就在这里踩坑了。。。


因此,总结下来经验教训就是:


  1. 向类中添加新成员时一定要注意其清理工作,使用前一定要确保该成员是崭新的,里面没有之前旧存货。

  2. 代码中添加必要的监控,有利于排查问题

  3. 测试的时间要稍微长一些,否则类似这里的问题不容易暴露

  4. 程序员遇到 bug 是很正常的,大胆假设,小心求证,每次问题的解决都是能力的提升


查到问题后,修 bug、自测、验证、代码提交一气呵成,再次上线就明天了,收工回家。


从下午上线发现问题到问题解决耗时超过 6 小时,博主到家时,已是满天繁星。


希望本文能帮助大家避开一些坑。


发布于: 2021 年 01 月 02 日阅读数: 28
用户头像

还未添加个人签名 2019.01.07 加入

公众号:码农的荒岛求生

评论

发布
暂无评论
意想不到,这个神奇的bug让我加班到深夜