调程序差点调出信仰（1）

本文试图描述在神秘莫测的逻辑面前，作为一个coder的经常会遇到的尴尬，无能为力和哭笑不得。用王小波的话表达这种体会就是：“我们的生活有这么多的障碍，真他妈的有意思”。

 

一切都得从DM冒烟测试说起。周一一早来到公司，测试部巨牛付sir走过来跟我说：“在211机器上，对称异步复制出了点问题，你看一下，应该很好解决的”。

连上了211机器。打开xml测试工具，把对称异步复制的测例跑了几遍。靠。对称异步复制，主服务器的语句能够传到从服务器，反之竟然不行。

细细看了下测试脚本，发现从服务器采用一个新建的库来做复制，初步断定是由于库名称和主服务器库名称不相同导致的这个问题，因为当初写代码时就没怎么考虑这些个方面。

手动构造这方面的测试用例，测试，竟然通过。看来在不同库之间的复制是不存在问题的。

会不会是对称复制的问题呢？改成非对称复制，问题依然存在，看来还用不着怀疑是对称复制的问题。

突然想起以前的经验：调试异步复制bug，首先要select * from sysasyncerrors, 看看复制过程中是否出现过错误。于是查询表sysasyncerrors，结果竟然为空，说明复制过程一切正常。接着又查询sysasyncdrecs表，发现表里面竟然有4条数据——这显然是不对滴。如果一切顺利的话， sysasyncdrecs表中的数据应该为空才对。问题似乎已经找到了：异步复制过程中，有一个事务的数据还保存在sysasyncdrecs表中，并没有发送到从服务器，导致从服务器缺少一条数据。

接下来的调试似乎就很简单了：只需要在异步复制代码的相应位置设置断点，跟踪调试，找到出现错误的环节。于是先重启服务器，设置了一大堆断点，然后选择好测试脚本，准备在时隔几个月后，再次深入到久违的复制代码，来一次彻底的调试，搞定这个bug。在一切开始之前，想到sysasyncdrecs表中的那4条数据，认为这4条数据纯属多余，不如将其删去，让数据库恢复到最初状态。于是顺手就把这4条数据给删掉了。

一切准备妥当。带着风萧萧兮易水寒，此bug不搞定就不吃午饭的决心，偶毅然绝然地按下了F5键。但见程序跳到了预设的第一个断点，接着又跳到了第二个，第三个….，直到最后一个。异步复制流程的每个步骤都被正常执行，一切顺利得不能再顺利。打开xml工具就被雷到了：测试工具竟然报告测试通过，这可是前几次测试从来没有过的事情。

当时下意识的反应就是去掉所有断点，全速再重跑一遍测例。测试的结果是，出错了。老天保佑，今天运气还不错。众所周知，不怕bug有多少，就怕它重现不了。不能重现的bug，它是上天给程序员安排下的冤家对头，是多线程，内存泄漏，野指针等一切靠谱和不靠谱东西的私生子，绝大多数时间里，它潜藏在辛苦写就的代码中，无声无息，不为程序员所见，但是在程序员信心满满的将自己代码check in后，它就会在测试人员手中,用户面前，幽幽闪现，飘忽不定，让原本自得意满的程序员百般调试都难以定位，然后觉得自己是个项目成本，累赘，麻烦制造者……

手工将sysasyncdrecs表清除掉，让数据库恢复最初状态，然后重新调试。靠……，测试又通过了。再测，又出错了。今天真是活见鬼了。

王老大去茶水间倒水，看到我傻愣在那里，于是他的管理线程启动了，线程的时间片分配到了我这里。我被从迷茫状态中唤醒，向他讲述了今天遇到的事情。王老大沉思片刻，说道：“异步复制有问题，那同步复制呢？这个，一般的来说啊，如果异步复制有问题，你就应该试试看同步复制有没有这个问题，尽量将问题简化。”说罢大手一挥，线程时间片到，状态由管理线程转入工作线程，端着茶杯走开了。

怀着对王老大的敬佩有如滔滔江水连绵不绝的心情，我停止了异步复制的测试，构造了一个同步复制测试的脚本。将脚本跑了几次，竟然没有发现问题。

时间已然下午5点半，天色微微向晚，而我也已筋疲力尽。算了，下班了，收拾东西奔小餐馆而去。

 

第二天是2009年3月3号，天气好转。太阳在厚重的铅色云彩间穿行，偶尔给这世界投射一点久违的阳光。去上班的路上我不禁想到小时候老师教过的儿歌，同时为自己老当益壮的记忆力深感欣慰。那首歌唱到：“又是一年三月三，风筝飞满天，风筝带着我们的思念，回到了童年……”。可是一到公司，我不是回到了童年，而是回到了梦魇——那个天杀的bug和昨天一样地固执：清理环境，一跑ok，再跑出错，剩下4条数据在sysasyncdrecs表里；再清理环境，再跑ok，又跑又出错，又剩下4条数据在sysasyncdrecs表里……。

时间还早，不可轻言放弃，特别是在这个天气好转的上午。怀着要一扫阴雨天气带来的阴郁情绪的决心，我打算来一次彻头彻尾的调试。

首先严重怀疑是从服务器的问题。为什么第一次执行测例没有问题，第二次就出错呢？会不会是从服务器执行计划重用的问题？于是在开始第二次测试之前，在从服务器上设置了一大堆断点，看看从服务器是否正确执行了收到的语句。

跟踪从服务器执行收到语句的过程，没有发现任何错误。每一条语句都被正确地接收，分析，执行，返回结果。

正在沉思之际，抬头瞥见王老大正在向我走来，眼睛盯着我的屏幕在看着呐。我知道，王老大的管理线程又启动了，于是向他说明目前碰到的问题。这回wld仔细看了测试脚本，然后进行以下分析：

“这个测试脚本，异步复制时间间隔为30秒，测试时，分别对主从服务器做INSERT，DELETE，UPDATE操作，每次操作完成后等待35秒，然后去另外一台服务器查找，看操作是否已经传递过去。会不会是等待35秒以后，异步复制操作还没有进行？”

“不可能吧，执行一条语句需要5秒吗？”我当即表示怀疑。

“先试试看把”，摸着石头过河是wld一贯的风格。

于是乎重新改写了测试脚本。这回只执行insert语句，遇错退出后不清理环境，以便查看是否在等待35秒后，异步复制还没有执行。

Wld这回猜对了。等待35秒过后，异步复制真的有可能没有进行。刹那间我以为bug就是出在这里了，但随即又进行了否定：即使35秒过后，异步复制没有进行，查询不到数据，但是异步复制始终是会进行的，这样操作完毕后，sysasyncdrecs表里剩下的4条数据又如何解释呢？