你好,我是雨乐!
在之前的文章中,我们有讲到如何定位内存泄漏和GDB调试-从入门实践到原理。今天,借助本文,来分享另外一种更为棘手的线上问题解决方案-如何在没有coredump文件的情况下,定位程序崩溃原因
。
前言
一个优秀的程序员,编码能力和解决问题的能力必不可少。编码能力体现的是逻辑思维能力
,而解决问题的能力不仅仅依靠自己经验的积累,更需要一定的敏锐嗅觉和使用其他方式解决问题的能力。管他黑猫白猫,抓住老鼠就是好猫。
在日常的项目开发中,根据Bug产生的时机和环境,我们可以将Bug细分为以下几种:
- 线下缺陷:此阶段发生在上线前。主要在测试阶段,由开发人员在自测过程中或者有测试人员发现
- 线上问题:此阶段发生在上线后,也就是在正式环境或者生产环境。主要是不符合产品的需求逻辑,可能会影响用户体验
- 线上故障:这个阶段是最严重的,对公司的收益、用户体验都会造成影响,主要为服务不可用等
在本文的示例中,我们针对的第三个阶段,即线上故障进行定位和分析的一种方式,希望借助本文,能够对你的故障定位能力有一定的帮助。
背景
早上到了公司,正在愉快地摸鱼,突然企业微信来了条报警,某个核心服务重新启动了。
于是,快速打开iterm,通过跳板机登录线上服务器,第一时间,查看有没有coredump文件生成:
代码语言:javascript复制ll /www/coredump/
total 0
竟然没有coredump文件,当时心情是这样的:
当时第一反应是有人手动重启了,于是在组内群里问了下,没人动线上,看来问题比较麻烦。
排查
既然没有coredump文件产生,且没有人手动重启服务,只能分析下系统日志,看看能得到什么线索。
通过在系统日志中,查找进程名来获取进程发生错误时候的日志信息。
代码语言:javascript复制grep xxx /var/log/messages
kernel: xxx[11120]: segfault at 7f855009e49f ip 0000003ab9a75f62 sp 00007fcccd7f74c0 error 4 in libc-2.12.so[3ab9a00000 18b000]
在上面的信息中:
- xxx 为进程名,后面括号中的11120代表当时的
线程id
- 7f855009e49f为出错时候的地址
- 0000003ab9a75f62为发生错误时指令的地址
- 00007fcccd7f74c0 为堆栈指针
- 3ab9a00000为libc在此程序中映射的内存基址
- segfault at和error 4这两条信息可以得出是内存读出错
其中,内核对error的定义如下:
代码语言:javascript复制/*
* Page fault error code bits:
*
* bit 0 == 0: no page found 1: protection fault
* bit 1 == 0: read access 1: write access
* bit 2 == 0: kernel-mode access 1: user-mode access
* bit 3 == 1: use of reserved bit detected
* bit 4 == 1: fault was an instruction fetch
* bit 5 == 1: protection keys block access
*/
enum x86_pf_error_code {
X86_PF_PROT = 1 << 0,
X86_PF_WRITE = 1 << 1,
X86_PF_USER = 1 << 2,
X86_PF_RSVD = 1 << 3,
X86_PF_INSTR = 1 << 4,
X86_PF_PK = 1 << 5,
};
#endif /* _ASM_X86_TRAPS_H */
error 4代表用户态程序内存访问越界
。
好了,通过上述内核日志,我们基本可以得出如下结论:
名为xxx的进程中,线程id为11120发生了用户态程序内存访问越界,且最终core在了libc-2.12.so中。原因基本确定,现在我们开始定位问题。
初步定位
使用ldd命令,查看可执行程序的依赖:
代码语言:javascript复制ldd xxx
linux-vdso.so.1 => (0x00007ffedb331000)
librt.so.1 => /lib64/librt.so.1 (0x0000003aba200000)
libdl.so.2 => /lib64/libdl.so.2 (0x0000003ab9600000)
libstdc .so.6 => /usr/lib64/libstdc .so.6 (0x0000003abce00000)
libm.so.6 => /lib64/libm.so.6 (0x0000003aba600000)
libc.so.6 => /lib64/libc.so.6 (0x0000003ab9a00000)
/lib64/ld-linux-x86-64.so.2 (0x0000562e90634000)
libpthread.so.0 => /lib64/libpthread.so.0 (0x0000003ab9e00000)
libgcc_s.so.1 => /lib64/libgcc_s.so.1 (0x0000003abc200000)
在上一节中,我们得到了程序发生错误时指令的地址(0000003ab9a75f62)以及libc-2.12.so在进程中的基址(3ab9a00000),下面我通过objdump
命令来进行分析。
反汇编
通过下述命令,得到libc-2.12.so汇编结果(因为内容较多,我们将其重定向输出到一个临时文件)
代码语言:javascript复制objdump -tT /lib64/libc-2.12.so > ~/info
查找汇编语句
Libc-2.21.so是个基础库,其内容多达58m,很难直接从中获取有用信息。
代码语言:javascript复制ll info
-rw-r--r-- 1 root root 58369282 Jan 28 10:14 info
为了快速定位错误点,我们抓取跟错误点地址3ab9a75f62相关的命令(为了获取上下文,所以grep了部分)
代码语言:javascript复制objdump -tT /lib64/libc-2.12.so | grep 3ab9a75
输出如下:
代码语言:javascript复制0000003ab9a75100 l F .text 0000000000000176 enlarge_userbuf
0000003ab9a756b0 l F .text 000000000000011b ptmalloc_lock_all
0000003ab9a757d0 l F .text 00000000000000b6 ptmalloc_unlock_all
0000003ab9a75890 l F .text 00000000000000c1 ptmalloc_unlock_all2
0000003ab9a75960 l F .text 0000000000000003 __failing_morecore
0000003ab9a75a20 l F .text 00000000000000da sYSTRIm
0000003ab9a75b00 l F .text 000000000000029d mem2chunk_check
0000003ab9a75da0 l F .text 00000000000000e0 malloc_printerr
0000003ab9a75e80 l F .text 0000000000000541 malloc_consolidate
0000003ab9a75280 l F .text 0000000000000187 _IO_str_seekoff_internal
0000003ab9a75970 l F .text 000000000000006b __malloc_check_init
0000003ab9a75410 l F .text 00000000000001aa _IO_str_overflow_internal
0000003ab9a759e0 l F .text 0000000000000031 __malloc_usable_size
0000003ab9a75020 l F .text 0000000000000062 _IO_str_underflow_internal
0000003ab9a750b0 l F .text 000000000000002b _IO_str_finish
0000003ab9a75090 l F .text 0000000000000012 _IO_str_count
0000003ab9a755c0 l F .text 00000000000000ae _IO_str_init_static_internal
0000003ab9a750e0 l F .text 0000000000000015 _IO_str_pbackfail_internal
0000003ab9a759e0 w F .text 0000000000000031 malloc_usable_size
0000003ab9a75020 g F .text 0000000000000062 _IO_str_underflow
0000003ab9a750e0 g F .text 0000000000000015 _IO_str_pbackfail
0000003ab9a75410 g F .text 00000000000001aa _IO_str_overflow
0000003ab9a75670 g F .text 000000000000001d _IO_str_init_readonly
0000003ab9a75690 g F .text 0000000000000012 _IO_str_init_static
0000003ab9a75280 g F .text 0000000000000187 _IO_str_seekoff
0000003ab9a750e0 g DF .text 0000000000000015 GLIBC_2.2.5 _IO_str_pbackfail
0000003ab9a75690 g DF .text 0000000000000012 GLIBC_2.2.5 _IO_str_init_static
0000003ab9a759e0 w DF .text 0000000000000031 GLIBC_2.2.5 malloc_usable_size
0000003ab9a75020 g DF .text 0000000000000062 GLIBC_2.2.5 _IO_str_underflow
0000003ab9a75280 g DF .text 0000000000000187 GLIBC_2.2.5 _IO_str_seekoff
0000003ab9a75410 g DF .text 00000000000001aa GLIBC_2.2.5 _IO_str_overflow
0000003ab9a75670 g DF .text 000000000000001d GLIBC_2.2.5 _IO_str_init_readonly
为了进一步定位问题点,我们使用objdump命令并指定起始点
objdump -d /lib64/libc-2.12.so --start-address=0x3ab9a75000 | head -n2000 | grep 75f62
输出如下:
代码语言:javascript复制3ab9a75ec8: 0f 85 94 00 00 00 jne 3ab9a75f62 <malloc_consolidate 0xe2>
3ab9a75f62: 48 8b 43 08 mov 0x8(%rbx),%rax
基本能够确定在进行malloc的时候,出现了问题。
精准定位
在上节中,我们定位到原因是malloc导致,但是代码量太大,任何一个对象底层都有可能调用了malloc(new也会调用malloc),所以一时半会,不知道从哪下手。
为了定位原因,采用最近定位法
,分析最近一次上线的代码改动,这次改动,将之前的redis Sentinel改为了redis cluster,而redis 官方没有提供cluster的client,所以自己手撸了个client,而在这个client中调用malloc顺序如下:
-> Init
--> redisClusterInit
----> calloc
------> malloc
好了,到此,进程崩溃的代码点基本定位了,下面我进行原因分析。
原因分析
程序对RedisClusterClient进行初始化的地方有两个:
- 程序启动的时候
- 当连接断开的时候
因为程序已经运行了一段时间,所以第一条基本不成立,那么我们看下本次改动使用的命令之一ZRangeByScore的实现:
代码语言:javascript复制void RedisClusterClient::ZRangeByScore(std::string& key, std::string min, std::string max,
std::vector<std::string> *vals,
bool withscores,
std::string *msg) {
// ....
redisReply *reply = static_cast<redisReply*>(
redisClusterCommandArgv(cc_, argv.size(), &(argv[0]), &(argvlen[0])));
if (!reply || reply->type != REDIS_REPLY_ARRAY) {
// ...
redisClusterFree(cc_);
cc_ = nullptr;
Init(host_, password_, &connect_timeout_, &op_timeout_, msg);
}
return;
}
// ...
}
单纯这块代码,是不会有问题的,所以需要把使用这块代码的都考虑进来。我们重新理下请求的调用链:
代码语言:javascript复制-> Load
--> GetHandler
----> GetSession
------> GetRedisClient
重新进行代码分析,发现在特定条件下,GetRedisClient可能会被多个线程同时调用,如果不进行Init的话,一切正常,而当一个线程Init的时候,恰好另外一个线程进行读,因此引起了访问一个已经释放的内存地址,所以导致了进程崩溃
。
这种情况发生的概率很低,很难重现。毕竟连接突然断开的同时,又有一个线程在同时访问,在线上还是很难出现(当然可以在线下通过tcpkill
进行模拟,这就是另外一回事了),总体来说,还是比较幸运,能够迅速定位。
问题解决
在整个bug的分析和解决过程中,定位segfault
是最困难的地方,如果知道了segfault的地方,分析原因,就相对来说简单多了。当然,知道了崩溃原因,解决就更不在话下了