Linux上定位后台服务偶发崩溃的解决方法

问题描述

在最近的后台服务中，新增将某个指令的请求数据落盘保存的功能。在具体实现时，采用成员变量来保存请求消息代理头，在接收响应以及消息管理类释放时进行销毁。测试反馈，该服务偶发崩溃。

问题分析

测试环境上运行的是rel版程序，由于在编译时去掉了调试信息（-g）以及开启O3级别优化，从崩溃dump的堆栈上，只看到程序崩溃的调用栈，函数入参等被优化掉，由于此处没有打日志，只能想其他办法来复现。猜测是重复释放指针导致的崩溃，接下来继续分析。

从rel版本的调用栈上看，只看见最后销毁的函数调用，而在实际代码中，有两处销毁的函数调用入口，为什么在dump中看到的调用栈顺序与实际代码不一致呢？猜测是开启O3优化，将函数内联。

做了以下实验来分析，

void test_dump()
{
	int* p = NULL;
	*p = 2;		// occur dump
}

void test_f2(int b)
{
	b += 1;
	test_dump();
}

void test_f1(int a)
{
	a+=1;
	test_f2(a);
}

int main()
{
 test_f1(1);
	return 0;
}

在Debug以及Rel模式下，触发崩溃，使用gdb来输出堆栈信息分别如下：

结论：在Rel模式下，O3级别的优化内联了调用函数，如果从崩溃点往上回溯有多个可能入口点，那仅凭dump信息不能确认是哪个入口触发的崩溃。

构造测试环境

通过分析代码，得知要触发可能的多重释放，需要构造一边创建，一边销毁的场景。

创建：可通过测试工具，定时高频发送特定指令，触发创建流程销毁：可在定时任务中，进行无效状态上报，触发销毁流程为了加快崩溃复现速度，创建以及销毁的速度需要合理匹配，如果太快销毁，会导致无法进入创建流程。经过分析尝试，最终设定测试工具每50毫秒发送一次，后台服务每50ms上报无效状态。

为进一步验证崩溃的想法，在销毁操作等关键路径添加日志，启动Rel版来重现。经过长时间的测试，获得了2次宝贵的崩溃dump以及对应的日志。每次dump要花费2个半小时甚至更多才能复现，说明这个问题是偶发问题，很可能与多线程竞态有关。复现该问题的时间成本有点高，不过，从获得的dump以及日志已足以定位问题。

日志分析

同一后台服务，不同业务模块的日志分布在不同日志文件中，在分析时，需要将各部分日志聚合起来，方便复现全流程。在聚合时，可以按需截取各模块的最后若干行日志，每种日志中包含正常以及异常的日志，将其汇总到单一文件，然后结合代码进行逐行关联分析。

在分析过程中，遇到一些框架方面的疑问，通过询问相关同事得到解答。目前的消息收发框架在接收消息时，先将消息放入线程池的消息队列，通过信号量来唤醒线程，线程从消息队列中获取消息，从消息中取出处理函数进行处理。
在应用层处理不同消息时，可能处理同一个变量时，会有发生竞态。通过对释放指针的分析，正常释放指针指都有一定的规律，当触发崩溃时，释放的指针值与正常的值有明显区别。

经验小结 发现有dump文件时，查看dump文件生成时间，将当时的日志以及可执行文件，连同dump文件一并放在独立的文件夹中，便于后续分析。因为当前的日志文件以及可执行文件可能被删除以及更新。每一次问题的解决，都是一次对已有系统的再深入认识，理解。构造复现环境时，要使用Rel版本，且只能通过日志来确认程序流程，而不是断点。在linux上，不能使用嵌套属性的互斥锁，它会破坏设计意图，让潜在的死锁更加难以发现。让错误尽早暴露好过后续找错。大胆假设，小心求证，胜利的曙光终会出现。