tomcat程式意外退出的問題分析（轉）

卡卡西村長發表於2016-05-18
Tomcat

原文連結：http://hongjiang.info/why-kill-2-cannot-stop-tomcat/

 

節前某個部門的測試環境反饋tomcat會意外退出，我們到實際環境排查後發現不是jvm crash，日誌裡有程式銷燬的記錄，從pause到destory的整個過程：

org.apache.coyote.AbstractProtocol pause
Pausing ProtocolHandler
org.apache.catalina.core.StandardService stopInternal
Stopping service Catalina
org.apache.coyote.AbstractProtocol stop
Stopping ProtocolHandler
org.apache.coyote.AbstractProtocol destroy
Destroying ProtocolHandler

從上面日誌來可以判斷：

1) tomcat不是透過指令碼正常關閉(viaport: 即透過8005埠傳送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被觸發，執行了銷燬邏輯

而這又有兩種情況，一是應用程式碼裡有地方用System.exit來退出jvm，二是系統發的訊號(kill -9除外，SIGKILL訊號JVM不會有機會執行shutdownhook)

先透過排查程式碼，應用方和中介軟體團隊都排查了System.exit在這個應用中使用的可能。那就只剩下Signal的情況了；經過一番排查後，發現每次tomcat意外退出的時間與ssh會話結束的時間正好吻合。

有了這個線索之後，銀時同學立刻看了一下對方測試環境的指令碼，簡化後如下：

$ cat test.sh
#!/bin/bash
cd /data/server/tomcat/bin/
./catalina.sh start
tail -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等子程式傳送某個退出的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)

經過核心組伯俞的協助，我們發現

a) 用 ctrl-c 終止當前test.sh程式時，系統events程式向 java 和 tail 兩個程式傳送了SIGINT 訊號
SIGINT [ 0 11  ] -> [ 0 20629 tail ] 
SIGINT [ 0 11  ] -> [ 0 20628 java ] 
SIGINT [ 0 11  ] -> [ 0 20615 test.sh ] 

注pid 11是events程式
b) 關閉ssh終端視窗時，sshd向下遊程式傳送SIGHUP, 為何java程式也會收到？
SIGHUP [ 0 11681 sshd: hongjiang.wanghj [priv] ] -> [ 57316 11700 bash ] 
SIGHUP [ 57316 11700 -bash ] -> [ 57316 11700 bash ]
SIGHUP [ 57316 11700 ] -> [ 0 13299 tail ] 
SIGHUP [ 57316 11700 ] -> [ 0 13298 java ] 
SIGHUP [ 57316 11700 ] -> [ 0 13285 test.sh ]

不過伯俞很忙沒有繼續協助分析這個問題(他給出了一些猜測，但後來證明並不是那樣)。

確定了是由signal引起的之後，我的疑惑變成了：

1) 為什麼SIGINT (kill -2) 不會讓tomcat程式退出？
2) 為什麼SIGHUP (kill -1) 會讓tomcat程式退出?

我第一反應可能是jvm在某些引數下(或因為某些jni)對os的訊號處理會不同，看了一下應用的jvm引數，沒有看出問題，也排除了tomcat使用apr/tcnative的情況。

我們看一下預設情況下，jvm程式對SIGINT和SIGHUP是怎麼處理的，用scala的repl模擬一下：

scala> Runtime.getRuntime().addShutdownHook(
            new Thread() { override def run() { println("ok") } })

對這個java程式分別用kill -2和kill -1發現都會導致jvm程式退出，並且也觸發shutdownhook。這也符合oracle對hotspot虛擬機器處理Signal的說明，參考這裡，SIGTERM,SIGINT,SIGHUP三種訊號都會觸發shutdownhook

看來並不是jvm的事，繼續猜測是否與程式的狀態有關？catalina.sh指令碼里並沒有使用start-stop-daemon之類的方式啟動java程式，start引數的執行方式簡化後指令碼相當於：

eval '"/pathofjdk/bin/java"' 'params' org.apache.catalina.startup.Bootstrap start '&'

就是簡單的把java放到後臺執行。當catalina.sh自身程式退出後，java程式的ppid變成了1

花了很多的時間猜測可能是OS層面的原因，後來發現並沒有關係。春節後回來讓少明和澗泉也一起分析這個問題，因為他們有c的背景，對系統底層知道的多一些，用了大半天時間，不斷猜測和驗證，最後確認了是Shell的原因。

SIGINT (kill -2) 不會讓後臺java程式退出的原因

為了簡便，我們用sleep來模擬程式，當我們在互動模式下：

$ sleep 1000 & 

$ ps -opid,pgid,ppid,stat,cmd -C sleep
  PID  PGID  PPID STAT CMD
 9897  9897  9813 S    sleep 1000

注意，程式sleep 1000的pid與pgid(程式組)是相同的，這時我們用kill -2是可以殺掉sleep 1000程式的。

現在我們把sleep程式放到一個指令碼里後臺執行：

$ cat a.sh
#!/bin/sh
sleep 4400 &
echo "shell exit"

執行a.sh指令碼之後，sleep 4400程式的pid與pgid是不同的，pgid是其父程式的id，即已經退出了的a.sh程式

$ ps -opid,pgid,ppid,comm -p 63376
  PID  PGID  PPID COMM
63376 63375     1 sleep

這時我們用kill -2是殺不掉sleep 4400程式的。

到了這一步，已經非常接近原因了，一定是shell對後臺程式signal_handler做了什麼手腳。少明實現了一個自定handler的命令看看是否對kill -2有效：

#include <stdio.h>
#include <signal.h>
#include <stdlib.h>

void my_handler(int sig) {
    printf("handler aaa\n");
    exit(0);
}

int main() {
    signal(SIGINT, my_handler);
    for(;;) { }
    return 0;
}

我們把編譯後的a.out命令在指令碼里以後臺方式執行：

$ cat a.sh
#!/bin/sh
/tmp/a.out &

這次再嘗試用kill -2去殺a.out程式，是可以的。這說明shell對signal_handler做手腳是在執行使用者邏輯之前，也就是指令碼在fork出子程式的時候就設定了。按照這個線索我們google後瞭解到: shell在非互動模式下對後臺程式處理SIGINT訊號時設定的是IGNORE。

互動模式與非互動模式對作業控制(job control)預設方式不同

為什麼在互動模式下shell不會對後臺程式處理SIGINT訊號設定為忽略，而非互動模式下會設定為忽略呢？還是比較好理解的，舉例來說，我們先某個前臺程式執行時間太長，可以ctrl-z中止一下，然後透過bg %n把這個程式放入後臺，同樣也可以把一個cmd &方式啟動的後臺程式，透過fg %n放回前臺，然後在ctrl-c停止它，當然不能忽略SIGINT。

為何互動模式下的後臺程式會設定一個自己的程式組ID呢？因為預設如果採用父程式的程式組ID，父程式會把收到的鍵盤事件比如ctrl-c之類的SIGINT傳播給程式組中的每個成員，假設後臺程式也是父程式組的成員，因為作業控制的需要不能忽略SIGINT，你在終端隨意ctrl-c就可能導致所有的後臺程式退出，顯然這樣是不合理的；所以為了避免這種干擾後臺程式設定為自己的pgid。

而非互動模式下，通常是不需要作業控制的，所以作業控制在非互動模式下預設也是關閉的（當然也可以在指令碼里透過選項set -m開啟作業控制選項）。不開啟作業控制的話，指令碼里的後臺程式可以透過設定忽略SIGINT訊號來避免父程式對組中成員的傳播，因為對它來說這個訊號已經沒有意義。

回到tomcat的例子，catalina.sh指令碼透過start引數啟動的時候，就是以非互動方式後臺啟動，java程式也被shell設定了忽略SIGINT訊號，因此在ctrl-c結束test.sh程式時，系統傳送的SIGINT對java沒有影響。

SIGHUP (kill -1) 讓tomcat程式退出的原因

在非互動模式下，shell對java程式設定了SIGINT，SIGQUIT訊號設定了忽略，但並沒有對SIGHUP訊號設為忽略。再看一下當時的程式層級：

|-sshd(1622)-+-sshd(11681)---sshd(11699)---bash(11700)---test.sh(13285)---tail(13299)

sshd把SIGHUP傳遞給bash程式後，bash會把SIGHUP傳遞給它的子程式，並且對於其子程式test.sh，bash還會對test.sh的程式組裡的成員都傳播一遍SIGHUP。因為java後臺程式從父程式catalina.sh(又是從其父程式test.sh)繼承的pgid，所以java程式仍屬於test.sh程式組裡的成員，收到SIGHUP後退出。

如果我們在test.sh裡設定開啟作業控制的話，就不會讓java程式退出了

#!/bin/bash
set -m  
cd /home/admin/tt/tomcat/bin/
./catalina.sh start
tail -f /home/admin/tt/tomcat/logs/catalina.out

此時java後臺程式繼承父程式catalina.sh的pgid，而catalina.sh不再使用test.sh的程式組，而是自己的pid作 為pgid，catalina.sh程式在執行完退出後，java程式掛到了init下，java與test.sh程式就完全脫離關係了，bash也不會 再向它傳送訊號。

相關文章