💎一站式轻松地调用各大LLM模型接口,支持GPT4、智谱、星火、月之暗面及文生图 广告
## 问题现象 最近我们的几个非生产实例中,均出现了由archiver进程产生的core dump文件,让人如临大敌:是不是遇到了PG的大BUG导致了crash? 先来看看这些core文件。由于我们在/proc/sys/kernel/core_pattern指定了存放core文件的目录,所以可以在这个目录里面找到这些core文件。幸运的是,这些core文件都不大,一般几百KB,没有对文件系统的存储空间造成压力: ~~~ $du -sh * 248K core.170254 248K core.242719 248K core.31624 ~~~ 使用file命令,看一下core文件的基本信息: ~~~ #file core.170254 core.170254: ELF 64-bit LSB core file x86-64, version 1 (SYSV), SVR4-style, from 'cp pg_xlog/00000001000000410000006E /xxxx/yyy/zzz/00000001000' ~~~ 可以看到,这些core文件由执行cp命令的进程产生,而且这个cp命令是在拷贝PG的xlog。因为我们设置了PG的archieve_command参数为’cp %f /xxx/yyy/zzz/%p’,所以判断这个执行cp命令的进程,应该是由归档进程调用,用于归档日志的。 根据我们以前的经验,crash一般是由于代码的Bug引起。难道系统的cp命令有Bug导致了core? ## 初步分析 我们用gdb看一下发生core dump时的调用栈: ~~~ $gdb postgres core.31624 Core was generated by `cp pg_xlog/000000010000004200000091 /xxx/yyy/zzz/00000001000'. Program terminated with signal 3, Quit. #0 0x0000003ed44da360 in ?? () Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.80.2.alios6.x86_64 (gdb) bt #0 0x0000003ed44da360 in ?? () #1 0x0000000000407df9 in ?? () #2 0x007da781c2f60000 in ?? () ...... ~~~ Oops,由于没有安装glibc的调试信息(debug info),看不到调用栈的函数名。但从上面的信息里面,我们得到了一个重要线索: ~~~ Program terminated with signal 3, Quit. ~~~ 就是说cp命令在执行的过程中,收到一个编号为3的信号。查看文档,这个信号就是SIGQUIT。这儿有两个疑问: 1. 为什么收到SIGQUIT后,会产生core文件? 2. 为什么归档进程在调用cp命令进行日志归档时,会收到SIGQUIT信号? 下面我们以这两个问题为线索进行分析。 ## 问题分析 ### 问题1 先看第1个问题,我们使用简单的脚本模拟一下。用一个脚本,不断的拷贝文件,我们使用较大的文件,以使cp命令运行的时间足够长: ~~~ $cat cp.sh while true ; do cp -fr bigfile bigfile_copy sleep 1 done ~~~ 在上述脚本运行过程中,再用另一个脚本不断的向其发送SIGQUIT信号: ~~~ $cat kill.sh while true ; do kill -3 `ps -ef |grep "cp -fr" |head -n 1 |awk -F' ' '{print $2}'` done ~~~ 注意,我们发送信号的目标进程必须是cp.sh进程的执行`cp -fr`命令的子进程,而不是cp.sh本身。这时,我们发现cp.sh的脚本收到了SIGQUIT信号: ~~~ cp.sh: line 7: 3683 Quit cp -fr /tmp/* /tmp2 cp.sh: line 7: 3879 Quit cp -fr /tmp/* /tmp2 ~~~ 但奇怪的是,系统的core目录并没用core文件产生。原来,Linux系统缺省的环境下,每个用户进程的core文件的size limit是0,需要显式增大size limit,才能打印出core文件。我们使用下面的命令,放开core文件的size limit: ~~~ ulimit -c unlimited ~~~ 再次运行cp.sh和kill.sh,发现core file 产生了! ~~~ $sh cp.sh cp.sh: line 7: 7222 Quit (core dumped) cp -fr bigfile bigfile_copy cp.sh: line 7: 7416 Quit (core dumped) cp -fr bigfile bigfile_copy cp.sh: line 7: 7605 Quit (core dumped) cp -fr bigfile bigfile_copy cp.sh: line 7: 7798 Quit (core dumped) cp -fr bigfile bigfile_copy ~~~ 看来,cp命令在收到SIGQUIT时,产生core文件是正常的。查阅文档和cp命令的源代码发现,原来,Linux下如果进程不对SIGQUIT信号做捕获(即不设置信号处理函数),进程在收到SIGQUIT的行为就是打印core文件并退出。 ### 问题2 现在再看第2个问题,为什么cp命令的进程会收到SIGQUIT信号?是不是Postmaster发出的呢? 仔细查看系统日志记录(位于/var/log/messages),发现系统出现过OOM(Out of Memory) Kill事件。就是说,PG实例使用了过多的内存,把系统内存耗光后,Linux系统发出了kill -9信号给某些占用内存较多的子进程。子进程收到Kill -9信号后,就会无条件退出。而Linux内核在子进程退出时,会向其父进程,即PG的Postmaster主进程发送SIGCHILD信号。从PG代码可以看到,Postmaster在处理这些SIGCHILD信号时,如果发现子进程是被Kill -9杀掉的,则要用发信号的方式通知所有子进程退出(除了像sysloger这种非关键进程外)。这时Postmaster向子进程发生的退出信号就是SIGQUIT!所以我们高度怀疑cp命令收到的SIGQUIT正是Postmaster发出的。 但有个疑问是,产生core文件的cp命令进程,是归档进程利用syscmd函数新启动一个独立的子进程,所以其实它是Postmaster进程的“孙子”进程;而Postmaster只是像它直接的子进程发送了信号,信号是如何到达这个孙子进程的呢? 仔细查看代码发现,原来,PG代码里面fork一个子进程后,会建立一个子进程组(Process Group),这个子进程fork出的进程,都会在这个进程组里面。向这个子进程发信号,组中所有进程都会收到。 ## 结论与解决方案 自此,谜底揭开,core文件的产生原因可以总结为,发生OOM Kill时,PG主进程会向所有子进程和子进程所拥有的Process Group发送Kill -3信号;另一方面,归档进程会fork子进程来执行归档命令(即cp命令),此子进程在归档进程的Process Group里面,故也收到了Kill -3信号。而且该进程会对信号执行缺省动作即产生core文件。所产生的core文件为cp命令的core文件(一般300k左右,对系统影响不大)。 我们知道,如果我们设置core file的size limit为0,就会阻止core文件产生。而对于出问题的PG实例,我们是在pg_ctl启动进程时加入了-c选项,将core file 的size limit去除;而所有Postmaster的子进程和孙子进程,又继承了父进程的size limit,导致core file产生。所以,此问题的一个规避方法为,对archive_command做如下设置: ~~~ archive_command='ulimit -c 0 && cp %p /u01/tmp/%f' ~~~ 这样在cp命令被归档进程调用时,其core file的size limit为0,即便收到SIGQUIT信号,也不会打印core dump file。