【文章摘要】
对于由多个模块协同工作的软件来说，程序处理的时序是非常重要的。当消息处理的顺序出现混乱时，程序就会出现异常。
本文基于作者的实际项目经验，对软件模块之间的时序问题进行了详细的分析，为相关软件问题的分析及解决提供了有益的参考。
【关键词】
C语言 时序 模块 开发 消息
一、问题描述
在某软件版本中，有两个模块(模块A与模块B)之间要进行通信。通信链路建立起来之后，模块A向模块B发消息，消息中携带了用户号码及序列号。在消息发送成功之后，模块A按照序列号将用户号码存放到一个全局变量中。
模块B在接收到模块A发的消息之后，解析出用户号码，并进行相关的处理。在处理完成之后，模块B将用户号码及序列号原样返回给模块A。模块A先根据接收到的序列号来查找原发送的用户号码，并与接收到的模块B返回的用户号码进行比较。若用户号码相同，则进行后续处理。
模块A与模块B之间的通信如图1所示。
图1 模块A与模块B之间的通信
在该软件版本进行自测的过程中，发现模块A发送的用户号码与模块B返回的用户号码不能匹配，故后续流程无法继续。
查看模块A的日志，打印的发送的用户号码和接收的用户号码是一样的，序列号也是相同的，但在用strncmp函数(用户号码变量为字符串类型)进行比较时就出现了问题。
二、模块A的程序执行流程
由于用户号码的比较是在模块A中完成的，因此这里主要关注模块A的程序执行流程。
模块A的程序执行流程如图2所示：
图2 模块A的程序执行流程
从图2可以看出，在模块A与模块B的消息交互过程中，时序显得非常的重要。如果消息的处理顺序没有定义好，就会出现模块A程序异常终止的情况。
三、问题原因初步分析
为了确定发送的用户号码和接收的用户号码是否真的不一样，我们在对两个号码进行比较的程序语句之前加了详细的日志，想要打印出发送的用户号码、序列号和接收的用户号码、序列号。
日志加好之后，我们重新运行了程序，发现接收的用户号码和序列号是正确的，而发送的用户号码和序列号打印出来的是空值。
怎么会这样呢？难道在发送的时候没有将用户号码和序列号拷贝到全局变量中去？
我们又在拷贝发送用户号码和序列号的程序语句之后加了日志，想要打印出发送的用户号码和序列号的值。重新运行程序之后，发现发送的用户号码和序列号是正确的，看来拷贝还是成功了的。
通过以上的分析，可以基本确定拷贝和解析都没有问题，看来可能是处理时序导致了用户号码不能匹配的问题。
四、问题定位
我们又将日志详细地查看了一遍，发现了一个奇怪的现象，那就是日志中打印出的接收模块B返回消息的时间要比拷贝用户号码及序列号的时间早。
为什么呢？我们对照查看了一下代码，发现在将消息发送到模块B之后，模块A休眠了一段时间之后再进行消息的拷贝。而模块B在极短的时间之内就返回了消息，此时模块A还处在休眠期，没有来得及将消息拷贝到全局变量中。
难道就是模块A休眠时间惹的祸？为了验证我们的猜想，我们直接将执行休眠的代码注释掉了来进行测试。程序重新运行之后，再查看日志，发现一切正常了，没有打印出模块A发送的用户号码与模块B返回的用户号码不能匹配的信息，而且模块A的后续流程也都执行到了。看来真是这个休眠时间闯祸了。
确实是这样的，模块B返回消息的时间极短，这样当在与全局变量中的用户号码进行比较时，其实是一个字符串类型的用户号码在与一个空值进行比较，当然会出现问题。这也与发送的用户号码和序列号打印出来的是空值的事实相吻合。
既然真相已经大白，我们就着手修改代码，将模块A中按照序列号拷贝用户号码到一个全局变量的代码放到了发送消息到模块B的代码之前，保留模块A休眠的代码。重新对修改后的程序进行了测试，一切就OK了。
五、总结
在本次时序问题的过程排查中，主要依靠程序日志来定位问题。
通过本次问题排查，我们总结出的经验有以下几个：
(1) 详尽的日志有助于问题的定位。为了更清楚地了解问题出现的位置，我们可以在程序的关键语句处添加上一些测试日志，供分析所用。
(2) 在消息处理顺序很重要的程序中，一定要理清程序执行的前后关系，防止流程“越位”的情况发生。
(3) 在排查问题的过程中，不要放过任何一个蛛丝马迹，要及时验证自己的想法，多对程序进行测试。
是程序就会有bug，因此，我们不要对程序中出现的问题耿耿于怀，要掌握排查问题的方法，这样才能够做到“以不变应万变”。通过解决不同的问题，我们才能得到锻炼，我们的开发能力才会得到提高。
(本人微博：http://weibo.com/zhouzxi?topnav=1&wvr=5，微信号：245924426，欢迎关注！)