一个无厘头的core dump问题定位

今天收到测试部门提的一个bug，bug的内容如下：

问题现象：
suse10服务器升级到suse11 SP2后，aaasevice、loginrpc、paycenter三个网元分别发生了一次core dump

使用dmesg查看：
[166996.321057] aaaservice[30535]: segfault at 7fc667d285e2 ip 00007fc619b5ca30 sp 00007fc5defda448 error 6 in libthrift-0.8.0.so[7fc619af8000+a7000]
[175616.589046] loginrpc[30324]: segfault at 7f217e4b4fb8 ip 00007f217e24bfb8 sp 00007f2155cffb58 error 4 in libthrift-0.8.0.so[7f217e210000+a7000]
[197539.833582] paycenter[30499]: segfault at 7f415b9f3fb8 ip 00007f415b78afb8 sp 00007f41382c9768 error 4 in libthrift-0.8.0.so[7f415b74f000+a7000]

服务器从suse 10升级到suse 11 sp2后，有三个使用thrift的网元core dump了。

gdb查看core 文件，可以提供线索的信息如下：

Try: zypper install -C "debuginfo(build-id)=bddef848141961caba26bc83b17e354010ef4107"
Missing separate debuginfo for /lib64/libexpat.so.1
Try: zypper install -C "debuginfo(build-id)=2696e815e28d6ef4fcb614baf8b7802891fd5341"

warning: .dynamic section for "/usr/local/lib/libthrift-0.8.0.so" is not at the expected address (wrong library or version mismatch?)

warning: .dynamic section for "/usr/local/lib/libactivemq-cpp.so.14" is not at the expected address (wrong library or version mismatch?)

warning: .dynamic section for "/usr/local/lib/libapr-1.so.0" is not at the expected address (wrong library or version mismatch?)

warning: .dynamic section for "/usr/local/lib/libaprutil-1.so.0" is not at the expected address (wrong library or version mismatch?)

用gdb查看堆栈信息，发现堆栈都是乱的，没有任何可用的信息：

Program terminated with signal 11, Segmentation fault.
#0  0x00007f217e24bfb8 in ?? ()
(gdb) where
#0  0x00007f217e24bfb8 in ?? ()
#1  0x00007f217e276229 in ?? ()
#2  0x00007f215001cf40 in ?? ()
#3  0x0000000000000000 in ?? ()
(gdb) 

查看系统core dump的日志：

Apr 24 03:12:57 linux-h9nh kernel: [175616.589046] loginrpc[30324]: segfault at 7f217e4b4fb8 ip 00007f217e24bfb8 sp 00007f2155cffb58 error 4 in libthrift-0.8.0.so[7f217e210000+a7000]

提示都和thrift的动态库有关系，比较测试环境和开发环境的动态库，动态库的版本都是一致的，开发环境运行的网元都没有任何问题，没有得到任何的线索。

继续分析core dump的时间点，发现都是在4月24号发生的core dump。

在没有任何信息的可能下，只能查看最近几天测试人员的操作，使用history命令查看历史记录，还好bash的history记录了操作的时间，然后看history里对thrift的操作，查看的信息如下：

linux-h9nh:/usr/webtvinstall/jkh/THRIFT_INSTALL # history | grep thrift
  738  2013-04-23 09:45:13 ./thrift_install.sh
  804  2013-04-23 09:48:38 tar xvf rpm_for_activemq_and_thrift.tar.gz
  806  2013-04-23 09:48:44 cd rpm_for_activemq_and_thrift
  852  2013-04-24 06:57:37 nm /usr/local/lib/libthrift-0.8.0.so
  883  2013-04-24 03:25:43 ls -ltr *thrift*
  894  2013-04-24 05:15:48 ls -l|grep thrift
  925  2013-04-24 05:26:10 vi thrift_install.sh 

发现测试人员在4月23号的17：45分重装了thrift。core dump都发生在重装之后，问题和重装有关？

于是通过日志查看三个网元的启动和core dump时间：

-rw-r--r-- 1 hitv hitv    3086 Apr 23 08:02 /var/log/hitv/aaaservice[13-04-23:08:03:39]
-rw-r--r-- 1 hitv hitv   45289 Apr 24 00:49 /var/log/hitv/aaaservice[13-04-24:00:49:20]

-rw-r--r-- 1 hitv hitv   1856 Apr 23 08:02 /var/log/hitv/loginrpc[13-04-23:08:03:40]
-rw-r--r-- 1 hitv hitv   2752 Apr 23 08:15 /var/log/hitv/loginrpc[13-04-24:03:13:05]

-rw-r--r-- 1 hitv hitv    7115 Apr 23 08:02 /var/log/hitv/paycenter[13-04-23:08:03:40]
-rw-r--r-- 1 hitv hitv 3365295 Apr 24 09:18 /var/log/hitv/paycenter[13-04-24:09:18:40]

发现一个共同的特点，网元都是在重装库之前启动的，core dump都发生在重装库之后，我们的网元都是服务的进程，只有接收到消息后才进行处理，根据以往的经验，换库后如果不重启网元，网元接收消息处理时会重新加载动态库，这个时候就会发生core dump。

到此，发现问题的原因，花费1.5个小时。