## 問題現象 最近我們的幾個非生產實例中，均出現了由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。