一次痛苦的Coredump定位过程

来源：互联网发布：人人网络代理编辑：程序博客网时间：2024/05/16 15:11

http://blog.sina.com.cn/s/blog_4d6f62190100qlkw.html

大约从5月份开始，一台Server开始出现重启Worker Coredump的问题，期间负责该Server的两位同事先后就该问题进行了定位排查，由于该问题测试开发环境不可重现以及Coredump的堆栈信息基本乱掉，无有用线索可用，因此问题一直未得到解决。最近的一个月，发现每次发配置重启Server，必然有一堆WorkerCoredump，运维和开发同事都觉得该问题需要继续深挖定位。

因此专门安排任务让我跟进处理该问题。

该问题难以定位解决原因主要有以下几个方面：

1. worker coredump基本集中在服务重启时刻，一个worker coredump一次之后很少再会出现coredump；

2. worker coredump生成的core文件，堆栈信息混乱，感觉出错点和bug点相差甚远；

3. 出现问题的时间太长有七个月的时间，相关代码变更过大，按照检查变更代码的方式走查困难；

4. 测试环境重现困难，之前有同事做过压力测试，无法重现重启时Coredump的问题。

下边简要说一下我处理该问题的整个过程（过程是痛苦的）

Step one:检查现网的Coredump文件

和其他两位同事一样，首先去现网查看coredump文件的信息，结果所获得的信息也一样，由于堆栈信息混乱，出错点不固定，总是在不同的代码上跳来跳去。

于是，在得不到任何有价值线索的情况下，走了以前同事走过的老路，压测以图在测试环境重现Coredump问题，最终无法重现。

Step two：review互动Coredump的代码

说实话，相关代码看了不下三遍，没有能够查处问题（其实问题就在业务逻辑代码中），这也证实了一句话，这种问题不一定能看出来。

Step three：按命令字server拆分

由于该Server本身包括了若干个接口，因此考虑在前端将Server按各个命令字分组，然后重启服务观察那组Server会出现Coredump，从而确定是由于那些命令字引起的Coredump，缩小排查定位范围。最终得到的结论是：其中的一个命令字导致服务重启时worker Coredump。

Step four：从Core文件堆栈信息混乱推测可能的coredump直接原因

由于Core文件堆栈信息混乱，因此推测可能是内存的越界些问题，写了自己不该写的内存，导致整个内存乱掉。在单独重启现网Server的时候，发现信息

*** glibc detected *** ./spp_interactive_worker: corrupted double-linked list: 0x097c6b58 ***

======= Backtrace: =========

/lib/libc.so.6[0xf75e3cb1]

/lib/libc.so.6[0xf75e3dd0]

/lib/libc.so.6[0xf75e5a09]

/lib/libc.so.6(malloc+0x86)[0xf75e7596]

/usr/lib/libstdc++.so.6(_Znwj+0x27)[0xf7783807]

/usr/lib/libstdc++.so.6(_ZNSs4_Rep9_S_createEjjRKSaIcE+0x6b)[0xf775f13b]

/usr/lib/libstdc++.so.6(_ZNSs4_Rep8_M_cloneERKSaIcEj+0x38)[0xf775fcf8]

/usr/lib/libstdc++.so.6(_ZNSs7reserveEj+0x48)[0xf7760868]

/usr/lib/libstdc++.so.6(_ZNSt15basic_stringbufIcSt11char_traitsIcESaIcEE8overflowEi+0xa3)[0xf77594a3]

/usr/lib/libstdc++.so.6(_ZNSt15basic_streambufIcSt11char_traitsIcEE6xsputnEPKci+0x81)[0xf775e321]

/usr/lib/libstdc++.so.6(_ZNKSt7num_putIcSt19ostreambuf_iteratorIcSt11char_traitsIcEEE13_M_insert_intImEES3_S3_RSt8ios_basecT_+0xf5)[0xf774c0b5]

/usr/lib/libstdc++.so.6(_ZNKSt7num_putIcSt19ostreambuf_iteratorIcSt11char_traitsIcEEE6do_putES3_RSt8ios_basecm+0x50)[0xf774c380]

/usr/lib/libstdc++.so.6(_ZNSolsEj+0xcd)[0xf7754d4d]

../lib/libinteractive.so(_ZN15CTopDishMapping6EncodeERSs+0x103)[0xf42eec41]

../lib/libinteractive.so(_ZN16InterActionSteal13UpdateTopDishERjjRSsS1_+0x1fc)[0xf428798a]

../lib/libinteractive.so(_ZN16InterActionSteal13API_StealFoodEjjRjRiRSs+0xbe1)[0xf42890a7]

../lib/libinteractive.so(_ZN15StealFoodAction6doImplER13UsrActionData+0x65)[0xf42895a3]

../lib/libinteractive.so(_ZN14QUsrActionBase4doitEv+0x47)[0xf428b4c5]

../lib/libinteractive.so(_ZN13RubbishHander12rspStealFoodEjPcjRSs+0x3c9)[0xf429aee1]

../lib/libinteractive.so(_ZN13RubbishHander4doitEjjPcjRSs+0xde)[0xf429cd0e]

../lib/libinteractive.so(_ZN8SService18spp_handle_processEPcjRS0_Rj+0x7f8)[0xf4314bde]

../lib/libinteractive.so(spp_handle_process+0x5d)[0xf4315071]

./spp_interactive_worker(_ZN3spp6worker14CDefaultWorker16ator_recvdata_v2EjPvS2_+0x165)[0x8062e11]

./spp_interactive_worker(_ZN5tbase6tcommu9tshmcommu10CTShmCommu4pollEb+0x93)[0x8078c97]

./spp_interactive_worker(_ZN3spp6worker14CDefaultWorker7realrunEiPPc+0x500)[0x8065e32]

./spp_interactive_worker(_ZN3spp4comm11CServerBase3runEiPPc+0x23c)[0x8067252]

./spp_interactive_worker(main+0x116)[0x80629da]

/lib/libc.so.6(__libc_start_main+0xdc)[0xf759587c]

./spp_interactive_worker(__gxx_personality_v0+0x95)[0x8062841]

从glibc打印出的信息和step three中的结论呼应，确实是其中的一个特定逻辑引起的core问题。而直接原因是由于内存分配链被损害了，导致分配内存coredump。

由于此处信息仍旧无法定位到具体的代码行上，因此就想到了不想进行的最终的处理措施，现网跑一valgrind，看看能否有发现。

Step five:现网跑valgrind

于是联系运维安装valgrind，准备跑程序查看。说明一点，在线网跑valgrind也是最终没有办法的办法，由于现网跑valgrind会降低worker 20-25倍的处理性能，因此必须要跑一次尽快退出，争取将对用户的影响降低到最低。结果在最终的valgrind日志中，发现了问题所在，

==15539==

==15539== Invalid write of size 4

==15539== at 0x747830E: InterActionSteal::API_StealFood(unsigned int, unsigned int, unsigned int&, int&, std::string&) (interaction_rubbish.cpp:931)

==15539== by 0x7478AEE: StealFoodAction::doImpl(UsrActionData&) (interaction_rubbish.cpp:1128)

==15539== by 0x747AA28: QUsrActionBase::doit() (useraction.h:199)

==15539== by 0x748A4DC: RubbishHander::rspStealFood(unsigned int, char*, unsigned int, std::string&) (hander.cpp:166)

==15539== by 0x748C645: RubbishHander::doit(unsigned int, unsigned int, char*, unsigned int, std::string&) (hander.cpp:52)

==15539== by 0x75187E1: SService::spp_handle_process(char*, unsigned int, char*&, unsigned int&) (service.cpp:955)

问题的直接原因：

借用C++ Primer中的一句话：任何改变vector 长度的操作都会使已存在的迭代器失效。例如，在调用push_back 之后，就不能再信赖指向 vector 的迭代器的值了。

小结：引起coredump的问题代码，其实最终看起来是一处很小的问题，但就是这个问题引起的coredump却包含了极大的不确定，有时候core，有时候不core，core了又看不到有价值的线索。所以，core问题的定位还是要在发现之后，尽早定位（起码我们可以采用查看变更代码的方法确认一下）。C++给了程序员很大的权利，也带来了极大的风险，在使用指针、迭代器等元素的时候一定要注意内存问题。

PS：valgrind还是很强大的，赞一下！