一条sleep语句引发的惨案

  我们的项目绝大部分都是基于java或者javaEE的应用,CTO早就有言在先,所有程序里面,不准有sleep语句。如果非要加上sleep语句,那么必须提出来,由项目的technical lead或者manager来决定是不是这么用 。

 

   去年参与的一个项目,被一条sleep语句差点整死。

   程序需要定时的从另外两台机器上按照时间获取5分钟一次的日志文件,然后对该日志文件进行处理。刚开始的时候,两台机器的日志文件在处理的时候,是单独处理的,所以,基本流程就是,先用ftp把日志抓过来,然后一个文件一个文件的进行日志分析。但是实际运行中发现,那两台机器有可能进行热切换,也就是说,机器A如果突然出问题,那么相关的链接就会切换到机器B,相关的日志信息也会记录到机器B上。由于该程序在进行日志分析的时候,时间是一个非常敏感的因素,一旦发生热切换,分析之后的数据就会出错。那么就必须要改进了。改进的时候,考虑到之前代码的重用,ftp部分可以重用,需要做的只是将两个文件按照时间顺序先合并,然后再处理,即可满足要求。改代码很顺利,测试也很顺利,上线之后看起来也挺顺利,也没有什么exception,看起来这个项目可以完美的结束了。

 

   悲惨的事情在一个月之后发生了,用户是一个月之后才会去对账,也就是拿其他系统的数据,跟我们进行日志分析之后的数据进行比对,发现数据缺失了很多。更悲惨的是,之前做这个系统的同事已经被派到其他项目组,虽然之前的code我一行都没有写,我也只能被迫自愿的硬着头皮接下来,去解决这个问题。

  

   首先,先去检查有错误数据的时间段的log,查看是否有exception或者告警——结果,一切正常;

   其次,请维护的同事获取到客户那边所有的日志文件,尝试在本地重现错误信息——结果,本地运行之后一切正常。

   再次,连入客户的系统,对比获取到缺失的数据。

   然后,开始猜测错误缘由。好吧好吧,既然与之前不同的地方只在于合并了文件,那么应该就在合并文件前后出的问题,去看看代码吧。


    一看代码不要紧!On My GOD!!!! 代码惊现sleep(15000)!!!! 15秒,为什么在这个地方,那么奇怪的sleep了15秒?原来,因为ftp部分功能重用了之前的代码,由于程序会定时去做FTP,为了等待ftp完成,在合并日志文件之前,就加了一个sleep 15秒的语句!!!好吧,sleep之后呢?居然只是简单的去检查了一下文件是否存在,只要文件存在就认为ftp已经传输完成。我彻底崩溃了,这段代码之前居然从来没有review过。

 

    没错,一个日志文件不超过5M,在局域网内,15秒时间按道理是够的,可是,可是任何相关的网络传输都不应该假设在某段时间之内完成。还有,FTP只要开始传输了,本地就会有这个文件存在。文件存在是不能作为判断ftp是否传输结束的标志。其实,由于ftp传输是同步,而且在系统里面已经对这部分使用了状态机,需要的是去判断状态机的状态即可。

 

    根据对代码的分析,再对照缺失的数据,发现确实因为FTP没有传完,导致日志文件合并时并不完整。总算是找到了原因,改起来也很快。不过为了帮客户恢复之前的数据,还是费了很多时间。

 

   这个血泪的教训之后,我们就把不准在代码里面随意写sleep加入代码规范中,要加也可以,必须拿出来好好的讨论和review。

原文地址:https://www.cnblogs.com/lben/p/2751760.html