進程無端消失的破案歷程

概述

前段時間公司有個系統的進程總是無端退出，在客戶那邊好好的，在家裏服務器上總是出現，並且出現的時間也沒啥規律，固然最終查出來仍是有規律的，不過這個規律比較特別。你們看了後面的內容以後就明白了，真的很特殊！

初步分析 進程Crash？

當同事找到個人時候，我第一反應是是否是進程Crash了，若是是crash，那一般狀況下會有crash的日誌，檢查了一遍，什麼日誌都沒有留下，固然有時候Crash了，JVM也確實也不會留下Crash日誌，不過這個特別罕見了，絕大部分是人爲操做了。

被OS Kill？

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

System.exit?

排除掉以上兩個因素以後，接着立刻就懷疑是否有什麼代碼執行過System.exit，因而從新編譯了一把JDK，在System的exit方法處打印了些日誌，因而坐等奇蹟的發生。

使人興奮的是，進程真的消失了，但是使人遺憾的是，咱們埋點的日誌並無出現。這讓我再次陷入沉思。

迴歸源碼

從日誌看確實是調用了ShutdownHook

因而找到addShutdownHook源碼的位置

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

繼續等待事情再次發生，果真沒多久，當天下午又發生了，打印了以下日誌

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

那接下來就是要找到爲何會收到這個信號了，這個信號又是誰發出的。

找出信號源

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

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

對於我這種比較喜歡自虐的人，通常會想怎麼就肯定這個就是我要找的代碼，以前從沒有寫過Object-C的代碼，想着是否有個相似java的jmap的工具可讓我看內存裏的對象的狀況，然而臨時沒找到，不過偶然發現mac自帶的Activity工具就能看到一些跡象，因而在Activity裏找到了iTerm2進程，而後對其內存數據進行了採樣，看可否抓到相似PTYTask. dealloc或者stop的調用棧，但是比較難模擬，由於存在時間差，點擊採樣的時候，很快就結束了，我還沒來得及關閉session。在看採樣報告的時候偶然看到了/usr/bin/sample的命令，原來Activity是採用這個命令進行採樣的，因而摸索了一把，真能搞起來，採樣的時間能夠自定義，間隔是1ms一次，這樣可讓我有充足的時間來操做了，因而在採樣開啓以後，不斷地開一個session，起一個進程，而後close，重複作了好幾回，結束採樣以後看採樣的輸出，還真的就抓到了PTYTask.stop的調用棧

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

那到此爲止咱們能夠確認的是

• 進程退出是由於收到了信號SIGHUP
• 而SIGHUP的發生是由於終端Session Close

那究竟是不是這種狀況呢？

從新覆盤問題現場

這個貌似不太可能，由於咱們的shell腳本里執行java的時候都會帶上&，這樣進程就會後臺運行，不會出現這種session的問題。看了下腳本，確實是帶上了&的，本身也模擬了幾遍，在一個shell裏調用帶有&的java命令，關閉終端java進程並不會退出。難道是由於同事的終端配置和個人不同？後來要同事發了它的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

這幾個時間點徹底沒有規律看起來，不過我忽然想起2019-01-18那天是週五，同事是在上海出差，而17:34:30那會應該是快下班了，或者那會正好從上海趕車回杭州，因而問了下那個點同事是否是準備回杭州了，同事說那會確實合上電腦準備趕車回杭州，因而我接着問其餘幾個時間是否是差很少也是合上電腦的時間，結果還真是那麼巧，既然這樣，那說明咱們的判斷方向是正確的了。

水落石出

後面忽然發現同事修改過這個啓動腳本，在腳本的最後加了行命令

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

難道是這個命令搞的鬼？

忽然想起一個問題來，父子進程的問題，假如說當咱們在shell里加了&跑的話，當父進程跑完以後，會直接將其掛到init進程下面，也就是你經過ps -ef去看它的父進程會是1號進程，可是若是原來的父進程沒有跑完，那其父進程仍然會是原來的進程，因此當咱們執行這個腳本的時候，一直被執行tail等待日誌輸出，這樣一來，若是咱們將當前窗口關閉了，那就意味着父進程會退出，而後給子進程發送SIGHUP的信號，因而致使java進程退出，可是若是咱們在tail日誌過程當中ctrl c了，那java進程會過繼給init進程，所以此時當咱們再關閉窗口的時候也不會給其發送SIGHUP的信號了。

通過驗證果真如此，至此這個消失的進程終於獲得瞭解釋，嗯，好在不是咱們代碼的問題，值得欣慰，畢竟咱們的代碼是要在客戶那邊運行的，必需要保證好穩定性。

推薦閱讀:
當心踩雷，一次Java內存泄漏排查實
跟Kafka學技術系列之時間輪

歡迎關注 PerfMa 社區微信公衆號，體驗專業JAVA分析工具