概述

前段時間公司有個系統的進程老是無故退出，在客戶那邊好好的，在家里服務器上老是出現，而且出現的時間也沒啥規(guī)律，當然最終查出來還是有規(guī)律的，不過這個規(guī)律比較特別。大家看了后面的內容之后就明白了，真的很特殊!

初步分析

進程Crash?

當同事找到我的時候，我***反應是是不是進程Crash了，如果是crash，那通常情況下會有crash的日志，檢查了一遍，什么日志都沒有留下，當然有時候Crash了，JVM也確實也不會留下Crash日志，不過這個特別罕見了，絕大部分是人為操作了。

被OS Kill?

既然不是Crash，那是不是系統存在內存泄露，被OS Kill了，不過很快通過dmesg也排除了，因為沒有看到任何kill的跡象。

System.exit?

排除掉以上兩個因素之后，接著馬上就懷疑是否有什么代碼執(zhí)行過System.exit，于是重新編譯了一把JDK，在System的exit方法處打印了些日志，于是坐等奇跡的發(fā)生。

令人興奮的是，進程真的消失了，可是令人遺憾的是，我們埋點的日志并沒有出現。這讓我再次陷入沉思。

回歸源碼

從日志看確實是調用了ShutdownHook

于是找到addShutdownHook源碼的位置

再次翻了一下JDK的源碼，除了正常退出，System.exit等之外還有哪些情況會調用這個Shutdown的Hook，于是將埋點埋到了Shutdown.runHooks方法里。

繼續(xù)等待事情再次發(fā)生，果然沒多久，當天下午又發(fā)生了，打印了如下日志

也就是說當時是收到了一個SIGHUP的信號，這個信號最終會讓進程退出，JVM對這個信號確實是沒有特殊處理的，因此沒有我們看到的Crash日志。

那接下來就是要找到為什么會收到這個信號了，這個信號又是誰發(fā)出的。

找出信號源

SIGHUP這個信號，最主要發(fā)生的場景是Shell終端關閉一個Session的時候會對該Session關聯的進程發(fā)送一個SIGHUP信號，這個信號默認是會退出進程的。為此我還特地下載了ITerm2(我和同事都是mac，用的iTerm2的終端)的源碼，還真找到了幾個發(fā)送SIGHUP信號的代碼

看名字PTYTask就能猜到了，這應該是一個seesion任務，于是進到代碼里看到主要是有兩個方法有發(fā)送SIGHUP信號給子進程，分別是dealloc和stop，其中stop會通過sendSignal函數給子進程發(fā)送SIGHUP信號。

對于我這種比較喜歡自虐的人，一般會想怎么就確定這個就是我要找的代碼，之前從沒有寫過Object-C的代碼，想著是否有個類似java的jmap的工具可以讓我看內存里的對象的情況，然而臨時沒找到，不過偶然發(fā)現mac自帶的Activity工具就能看到一些跡象，于是在Activity里找到了iTerm2進程，然后對其內存數據進行了采樣，看能否抓到類似PTYTask. dealloc或者stop的調用棧，可是比較難模擬，因為存在時間差，點擊采樣的時候，很快就結束了，我還沒來得及關閉session。在看采樣報告的時候偶然看到了/usr/bin/sample的命令，原來Activity是采用這個命令進行采樣的，于是摸索了一把，真能搞起來，采樣的時間可以自定義，間隔是1ms一次，這樣可以讓我有充足的時間來操作了，于是在采樣開啟之后，不斷地開一個session，起一個進程，然后close，重復做了好幾次，結束采樣之后看采樣的輸出，還真的就抓到了PTYTask.stop的調用棧

這也就驗證了我close session的時候確實會給對應的子進程發(fā)送SIGHUP的信號。

那到此為止我們可以確認的是

• 進程退出是因為收到了信號SIGHUP
• 而SIGHUP的發(fā)生是因為終端Session Close

那到底是不是這種情況呢?

重新復盤問題現場

這個貌似不太可能，因為我們的shell腳本里執(zhí)行java的時候都會帶上&，這樣進程就會后臺運行，不會出現這種session的問題。看了下腳本，確實是帶上了&的，自己也模擬了幾遍，在一個shell里調用帶有&的java命令，關閉終端java進程并不會退出。難道是因為同事的終端配置和我的不一樣?后來要同事發(fā)了它的iTerm2里的seesion的配置給我看了下，和我的完全一樣，這就挺奇怪了。

于是再回過來看看之前的幾次進程消失時候的日志(我要同事有保留)，看到那幾個進程退出的時間點，分別是

• 2019-01-14 20:42:52
•  2019-01-15 18:34:00
• 2019-01-18 00:57:58
• 2019-01-18 17:34:30

這幾個時間點完全沒有規(guī)律看起來，不過我突然想起2019-01-18那天是周五，同事是在上海出差，而17:34:30那會應該是快下班了，或者那會正好從上海趕車回杭州，于是問了下那個點同事是不是準備回杭州了，同事說那會確實合上電腦準備趕車回杭州，于是我接著問其他幾個時間是不是差不多也是合上電腦的時間，結果還真是那么巧，既然這樣，那說明我們的判斷方向是正確的了。

水落石出

后面突然發(fā)現同事修改過這個啟動腳本，在腳本的***加了行命令

java xxxx & 
cd $DIR_LOG && tail -f common-*.log 

難道是這個命令搞的鬼?

突然想起一個問題來，父子進程的問題，假如說當我們在shell里加了&跑的話，當父進程跑完之后，會直接將其掛到init進程下面，也就是你通過ps -ef去看它的父進程會是1號進程，但是如果原來的父進程沒有跑完，那其父進程仍然會是原來的進程，所以當我們執(zhí)行這個腳本的時候，一直被執(zhí)行tail等待日志輸出，這樣一來，如果我們將當前窗口關閉了，那就意味著父進程會退出，然后給子進程發(fā)送SIGHUP的信號，于是導致java進程退出，但是如果我們在tail日志過程中ctrl c了，那java進程會過繼給init進程，因此此時當我們再關閉窗口的時候也不會給其發(fā)送SIGHUP的信號了。

經過驗證果然如此，至此這個消失的進程終于得到了解釋，嗯，好在不是我們代碼的問題，值得欣慰，畢竟我們的代碼是要在客戶那邊運行的，必須要保證耗穩(wěn)定性。

【本文是51CTO專欄作者李嘉鵬的原創(chuàng)文章，轉載請通過微信公眾號(你假笨，id:lovestblog)聯系作者本人獲取授權】

戳這里，看該作者更多好文