節(jié)前某個部門的測試環(huán)境反饋tomcat會意外退出,我們到實際環(huán)境排查后發(fā)現不是jvm crash,日志里有進程銷毀的記錄,從pause到destory的整個過程:
org.apache.coyote.AbstractProtocol pause
Pausing ProtocolHandlerorg.apache.catalina.core.StandardService stopInternalStopping service Catalinaorg.apache.coyote.AbstractProtocol stopStopping ProtocolHandlerorg.apache.coyote.AbstractProtocol destroyDestroying ProtocolHandler從上面日志來可以判斷:
1) tomcat不是通過腳本正常關閉(viaport: 即通過8005端口發(fā)送shutdown指令)
因為正常關閉(viaport)的話會在 pause 之前有這樣的一句warn日志:
org.apache.catalina.core.StandardServer await
A valid shutdown command was received via the shutdown port. Stopping the Server instance.然后才是 pause -> stop -> destroy
2) tomcat的shutdownhook被觸發(fā),執(zhí)行了銷毀邏輯
而這又有兩種情況,一是應用代碼里有地方用System.exit來退出jvm,二是系統(tǒng)發(fā)的信號(kill -9除外,SIGKILL信號JVM不會有機會執(zhí)行shutdownhook)
先通過排查代碼,應用方和中間件團隊都排查了System.exit在這個應用中使用的可能。那就只剩下Signal的情況了;經過一番排查后,發(fā)現每次tomcat意外退出的時間與ssh會話結束的時間正好吻合。
有了這個線索之后,銀時同學立刻看了一下對方測試環(huán)境的腳本,簡化后如下:
$ cat test.sh#!/bin/bashcd /data/server/tomcat/bin/./catalina.sh starttail -f /data/server/tomcat/logs/catalina.out
tomcat啟動為后,當前shell進程并沒有退出,而是掛住在tail進程,往終端輸出日志內容。這種情況下,如果用戶直接關閉ssh終端的窗口(用鼠標或快捷鍵),則java進程也會退出。而如果先ctrl-c終止test.sh進程,然后再關閉ssh終端的話,則java進程不會退出。
這是一個有趣的現象,catalina.sh start方式啟動的tomcat會把java進程掛到init(進程id為1)的父進程下,已經與當前test.sh進程脫離了父子關系,也與ssh進程沒有關系,為什么關閉ssh終端窗口會導致java進程退出?
我們的推測是ssh窗口在關閉時,對當前交互的shell以及正在運行的test.sh等子進程發(fā)送某個退出的Signal,找了一臺裝有systemtap的機器來驗證,所用的stap腳本是從澗泉同學那里copy的:
function time_str: string () {return ctime(gettimeofday_s() + 8 * 60 * 60);}probe begin {printdln(" ", time_str(), "BEGIN");}probe end {printdln(" ", time_str(), "END");}probe signal.send {if (sig_name == "SIGHUP" || sig_name == "SIGQUIT" || sig_name=="SIGINT" || sig_name=="SIGKILL" || sig_name=="SIGABRT") {printd(" ", time_str(), sig_name, "[", uid(), pid(), cmdline_str(), "] -> [", task_uid(task), sig_pid, pid_name, "], ");task = pid2task(pid());while (task_pid(task) > 0) {printd(" ", "[", task_uid(task), task_pid(task), task_execname(task), "]");task = task_parent(task);}println("");}}模擬時的進程層級(pstree)大致如下,tomcat啟動后java進程已經脫離test.sh,掛在init下:
|-sshd(1622)-+-sshd(11681)---sshd(11699)---bash(11700)---test.sh(13285)---tail(13299)
經過內核組伯俞的協助,我們發(fā)現
a) 用 ctrl-c 終止當前test.sh進程時,系統(tǒng)events進程向 java 和 tail 兩個進程發(fā)送了SIGINT 信號
新聞熱點
疑難解答