第一次遇到死锁——记一次程序卡住问题的错误排查过程

10月24日，周四

　　我负责的游戏启动程序（Launcher）更新上线后，临下班前接到运营消息，反映部分网吧启动Launcher后无反应。跑到客服现场，通过QQ远程桌面观察到如下现象：双击程序图标后，程序出现在任务管理器进程列表里，但无任何其它反应，没有任何界面弹出；然后程序就一直这样无任何响应，只能在任务管理器中把进程杀掉。

　　于是在现场通过Process Explorer抓出几个dump——任务管理器中没有转储dump的选项，只好用Process Explorer抓。这些dump均显示程序卡在了WinVerifyTrust这个Windows API上，即卡在了数字签名验证上。

　　由于之前已经有过WinVerifyTrust响应慢的经验（只是技术总监表示这种情况不会在外网发生），我当即发信给所有相关人员（包括运营产品部负责人B、项目制作人J和技术总监等），说明情况，询问是否要立即把WinVerifyTrust放到另一个线程，并提供紧急修复。

　　J否定了我的思路。他没有清楚地说明为什么我的思路不对，只是问改成多线程会有什么后果。我想可能是因为我给出的原因不具有说服力，没说出为什么会卡在数字签名上，且我的解决方案也只是规避，并没有从根本上解决问题。同时B表示没理解我的意思，且这次更新所对应的代码改动和数字签名毫无关系，之前也没出现过这种卡在数字签名上的现象。

　　J在公司附近找到了一家能稳定重现该问题的网吧。于是下班后我们俩在那家网吧一直待到半夜12点，在现场研究这个问题。期间J还跟我谈到了看现场的重要性。我们公司另一个网游项目曾经遇到过一个问题：部分网吧的游戏客户端没有声音。项目团队研究了几个月都没有进展。后来J在北京探亲时正好路过一个能重现该bug的网吧，进去研究了一番，发现客户端一配置文件有问题，这是由网吧硬盘的不可写导致的。他立即将此事告知该项目的制作人，于是bug很快得到修复。

　　回到我们Launcher的问题。在网吧的研究结果如下：

　　1、我们是10月23日同步并推送的程序，但网吧里的程序文件的修改日期是9月24日。不过查看这些文件的数字签名，发现仍是10月23日，且数据文件中记录的版本号已是最新，说明10月23日确实向网吧推送过版本。因此我们首先有一个猜测：会不会是运维错误地推送了老的版本。然而，此结论不能解释为什么无法启动的现象只在部分网吧出现；而且我发现我们新加的一个功能已经出现在那个网吧的客户端中，这个现象更是与我们的猜测矛盾。

　　2、考虑到我的程序经过加壳加签名才会发布到线上，因此我又跑回公司，重新编译了一个未加壳未加签名的exe拿去该网吧继续测试。结果该exe在该网吧却能正常运行，似乎可以初步确定该问题与加壳或数字签名有关。

　　我本打算在网吧现场抓几个dump，进行现场调试，但没想到Process Explorer竟然无法在网吧里运行，一启动就会报错，估计是没有权限。因此决定等第二天和运维部门沟通，确认版本是否正确。

10月25日，周五

　　通过和运维部门的沟通（此过程略去N多字）得知，文件的最后修改时间是不可靠的，还是要以MD5和数字签名为准。的确，后来我也从资料得知，文件的最后修改时间是可以通过SetFileTime系统API来修改的。而我们也将修改时间正确的加壳加签名的exe放在了那个网吧里，仍然无法正常启动。因此可以确认之前的文件修改时间是不可靠的。运维并没有给错版本。

　　这一天我和运维人员K到网吧去了两趟。K带了很多Sysinternals的工具过去，但全都无法运行。不过这天我们的排查工作还是有一定进展。我们发现，即便我将代码回滚到9月24日同步的版本（即此次更新前的线上版本），重新编译了一个exe，加壳加签名后仍然无法在那个网吧正常启动。因此可以确定此问题和加壳加签名有关。（可见代码版本控制的重要性。）

　　同时从运维人员F处得知，9月24日之后，运维使用的加壳软件有过更新。这更加说明加壳软件是值得怀疑的对象。F曾在微软做过技术支持，对此类问题应该更有经验。可惜F正在休假中，只能等下周一。同时F也开始发信