标签 程序员 下的文章

疏忽大意招致恼人'BUG'

河南项目实施,一波刚平一波又起呀!

前天凌晨,河南又割入很多家SP,昨天早晨上班通过日志发现程序的一个子模块进程隔一段时间重启若干次,通常是每一批数据推过来,就有一次重启的过程,日志中没有打印出出错的标志,进程莫名奇妙的就宕掉了,查看程序环境也没有发现CORE文件或者.assert文件,在代码关键的退出区域加入打印日志,重启系统后仍然有同样的问题。郁闷呀,没办法,在家里搭建测试环境,模拟测试,测试人员果然发现问题了,我定睛瞧看,哇,原来如此,测试的那个哥们是在前台启动的系统,这样shell输出的信息也能看得到,也就是说在后台日志文件中看不到的,在前台都看得到,那个模块之所以重启的原因是因为没有找到dso中的函数符号,换句话说就是我们在编译dso时忘记了链接某个.o文件了。这个功能是年初后加入到系统中的,真想不起来当时是如何测试的了,居然这样的问题都没有发现。打开Makefile查看,的确链接串中并没有该.o文件。修改后,重新编译,替换dso,重启程序,一切正常了。事后一想以前没有暴露出该问题是因为以前的消息处理流程没有走到这个分支,由于第二次割接导致出现新类型的消息,走到了该分支,问题因此暴露。

第二个问题也是疏忽所致。C里面最容易犯的就是忘记释放内存或者文件句柄之类的问题,这次让我遇到了。系统每天凌晨要生成一个清单文件,然后将该清单文件转移到指定目录下待被取走。程序在凌晨的时候的确准时生成了一份清单文件,但是用vi打开这份清单文件,vi提示最后一行不全,这才发现原来这个文件还没有写完,就被中断了。一位老同事马上用他的经验判断文件没有close就被移走或者改名了,这样系统缓存中的数据还没来得急写入文件就丢了,现象的确也是如此。查看代码,果不其然,唉这种低级错误都犯了。

切记:远离疏忽大意,说起来容易做起来难呀。

一个'莫须有'的BUG

上周三晚,河南’前线’反馈,河南移动手机用户投诉,经查是话单丢失。查看后的确有蹊跷,按照数据库中录入的原始话单数据来看,这几条记录的确是该生成话单的。之后又有同事发现出现丢话单的问题不仅仅这几条,而是一批一批的。没什么头绪,一夜无话,周四发现每天入库的可生成话单记录数居然比话单多出100万,也就是说我的程序居然少生成了100万话单,按照一条记录1角钱,这也是10万块呀,事情紧迫,问题查找的历程开始。

周四一上班,一封封邮件飞入我的邮箱。我们采取两个办法:
1. 继续分析现网的情况,通过统计数据来找;
2. 在家里这边搭建一套现网环境,来模拟运行,看是否能找出端倪。

还好我们的程序自身带一个统计工具,用来统计生成话单的数量,打开统计文件,核对数据,发现在当天的确生成的话单数要少于从数据库统计的话单数,而且也的确近100万。心头顿生郁闷呀。我们的程序以前的测试过程中从未出现过类似的情况,难道是以前测试的不够彻底,疑惑。

这里简单介绍一下我们的程序,这是一个消息的后处理程序,主要负责生成移动计费中心的计费需要的原始记录文件,我们也叫话单;再有就是把原始记录入库,用来查找统计生成报表。这个程序是一个多进程架构的程序,运行时多个进程互相配合,通过内存队列和文件来做接口,通过灵活的配置衔接两个进程之间的接口,所以说如果配置不当,出现上述现象的可能性还是有的,因此第一我就仔细的查看了配置情况,试图找出可疑之处以解释问题的缘由。可遗憾的是配置都很正确,不存在重复推队列以及推错队列的可能。此时又由于备份的系统输入数据已经被误删除,所以还得等上一些时间,在这段时间我又在系统的一个关键路径上安装的统计工具,我想看看到底是哪出了问题。

我发现事情都喜欢箍堆,这几天自己的私事也不少,周四下午由于私事没能更新代码,周五晚上才更新的代码并同步到现网,等待着运行一段时间后的统计结果。周六上午仍然办私事,中午同事的电话打来说我加的统计数据不准确,赶忙回公司登陆到现网看结果,发现从周六00:00~10:00期间,一共入库约115万条记录,话单也是约115万,也就是说从这个关键路径上流过的数据是约115万,而同事从数据库中统计的数字居然是147万而且居然发现有7万多的数据有重复(数据库没有设置唯一性约束),没有重复的数据有132万。也就是说我们的程序不仅仅是少生成话单了,而且还重复插入数据了。当时就有些发晕,代码是查了一遍又一遍呀,找不到什么问题。而且统计了原始记录文件,我们系统ftp取来的原始记录文件中的记录数就是约115万左右,和我加的统计工具统计的数值一致,也就是说问题不是少生成话单了,而是多入库和重复入库了。关键路径上的统计数据是115万,那么问题可能出现在后面的模块,统计了最后一步入库操作的输入(文件格式),发现数据量也是115万,从日志上看也是115万,真是邪了门了。数据库中怎么就无端出现多出来的数据呢,问了同事是否是数据库上某个JOB在自动复制数据,得到的回答是否定的。唯一向数据库中写数据的只有我们的程序。

疑惑和彷徨中发现一个奇怪现象:数据库里重复的数据都是来自数据源主机1的(我们有两台数据源主机),同事把数据库中重复数据的处理时间Show给我看,我根据那时间,查看了对应时间段的日志,发现一处可疑情况。我们的程序第一个工作就是从数据源主机上取原始数据文件,方式采用ftp get,如果get成功,我们会删除数据源主机上的源数据文件,我从日志中发现其中一处报了一个错误:ftp delete failed, errcode = (22)!,我顿时感觉难道这块是删除失败,重新ftp get导致重复数据的根源吗?我继续往下查发现程序并没有重复取那个文件,也就是说在数据源主机上那个文件已经不存在了。事情蹊跷,把这一现象告诉同事,他问我问什么会这样,我也解释不清楚。

继续查找,仍无头绪,遂决心在各个模块的入口出口加入统计信息,来查找问题所在,当时已经是周五23点30分了,带着疲倦改代码,这时同事突然想到了一点,那就是难道有另外一个一模一样的程序运行在别的主机上?如果真的存在,那么一切上述奇怪现象就都可以解释了。我停掉我们的程序,之后发现数据源主机1上的原始数据文件仍然被不知名程序取走了,我的同事马上逐个查找各台主机,终于在其中一台主机上发现了我们的程序,这个程序是上次测试时启动的,然后忘记停了,而新的程序则部署在另一台机器上。

唉,终于水落石出了。

丢话单:因为另一个程序把原始记录文件抢走,生成话单就放在了它的那台主机上,计费中心并不知道,也就没法获取该话单;
重复入库:两个我们的程序同时取到了原始记录文件,各自入了一份,由于数据库没有唯一性校验,所以导致重复入库。
多入库:还是因为另一个程序把原始记录文件抢走并入库,导致我们的统计工具统计不到该记录数量,所以少于数据库的统计量。

查了半天,费了半天劲,原来居然是一个’莫须有’的BUG,这也提醒了我们以后部署程序上线检查时一定要细心,否则这样的问题查起来很难,如果不是那位同事突然想起来,估计我现在还在苦苦挣扎在这个’莫须有’的BUG上呢。

如发现本站页面被黑,比如:挂载广告、挖矿等恶意代码,请朋友们及时联系我。十分感谢! Go语言第一课 Go语言精进之路1 Go语言精进之路2 Go语言编程指南
商务合作请联系bigwhite.cn AT aliyun.com

欢迎使用邮件订阅我的博客

输入邮箱订阅本站,只要有新文章发布,就会第一时间发送邮件通知你哦!

这里是 Tony Bai的个人Blog,欢迎访问、订阅和留言! 订阅Feed请点击上面图片

如果您觉得这里的文章对您有帮助,请扫描上方二维码进行捐赠 ,加油后的Tony Bai将会为您呈现更多精彩的文章,谢谢!

如果您希望通过微信捐赠,请用微信客户端扫描下方赞赏码:

如果您希望通过比特币或以太币捐赠,可以扫描下方二维码:

比特币:

以太币:

如果您喜欢通过微信浏览本站内容,可以扫描下方二维码,订阅本站官方微信订阅号“iamtonybai”;点击二维码,可直达本人官方微博主页^_^:
本站Powered by Digital Ocean VPS。
选择Digital Ocean VPS主机,即可获得10美元现金充值,可 免费使用两个月哟! 著名主机提供商Linode 10$优惠码:linode10,在 这里注册即可免费获 得。阿里云推荐码: 1WFZ0V立享9折!


View Tony Bai's profile on LinkedIn
DigitalOcean Referral Badge

文章

评论

  • 正在加载...

分类

标签

归档



View My Stats