新聞中心
概述

成都創(chuàng)新互聯(lián)公司是一家專注于做網(wǎng)站、網(wǎng)站制作與策劃設(shè)計,淶水網(wǎng)站建設(shè)哪家好?成都創(chuàng)新互聯(lián)公司做網(wǎng)站,專注于網(wǎng)站建設(shè)十載,網(wǎng)設(shè)計領(lǐng)域的專業(yè)建站公司;建站業(yè)務(wù)涵蓋:淶水等地區(qū)。淶水做網(wǎng)站價格咨詢:028-86922220
前段時間公司有個系統(tǒng)的進(jìn)程老是無故退出,在客戶那邊好好的,在家里服務(wù)器上老是出現(xiàn),而且出現(xiàn)的時間也沒啥規(guī)律,當(dāng)然最終查出來還是有規(guī)律的,不過這個規(guī)律比較特別。大家看了后面的內(nèi)容之后就明白了,真的很特殊!
初步分析
進(jìn)程Crash?
當(dāng)同事找到我的時候,我***反應(yīng)是是不是進(jìn)程Crash了,如果是crash,那通常情況下會有crash的日志,檢查了一遍,什么日志都沒有留下,當(dāng)然有時候Crash了,JVM也確實也不會留下Crash日志,不過這個特別罕見了,絕大部分是人為操作了。
被OS Kill?
既然不是Crash,那是不是系統(tǒng)存在內(nèi)存泄露,被OS Kill了,不過很快通過dmesg也排除了,因為沒有看到任何kill的跡象。
System.exit?
排除掉以上兩個因素之后,接著馬上就懷疑是否有什么代碼執(zhí)行過System.exit,于是重新編譯了一把JDK,在System的exit方法處打印了些日志,于是坐等奇跡的發(fā)生。
令人興奮的是,進(jìn)程真的消失了,可是令人遺憾的是,我們埋點的日志并沒有出現(xiàn)。這讓我再次陷入沉思。
回歸源碼
從日志看確實是調(diào)用了ShutdownHook
于是找到addShutdownHook源碼的位置
再次翻了一下JDK的源碼,除了正常退出,System.exit等之外還有哪些情況會調(diào)用這個Shutdown的Hook,于是將埋點埋到了Shutdown.runHooks方法里。
繼續(xù)等待事情再次發(fā)生,果然沒多久,當(dāng)天下午又發(fā)生了,打印了如下日志
也就是說當(dāng)時是收到了一個SIGHUP的信號,這個信號最終會讓進(jìn)程退出,JVM對這個信號確實是沒有特殊處理的,因此沒有我們看到的Crash日志。
那接下來就是要找到為什么會收到這個信號了,這個信號又是誰發(fā)出的。
找出信號源
SIGHUP這個信號,最主要發(fā)生的場景是Shell終端關(guān)閉一個Session的時候會對該Session關(guān)聯(lián)的進(jìn)程發(fā)送一個SIGHUP信號,這個信號默認(rèn)是會退出進(jìn)程的。為此我還特地下載了ITerm2(我和同事都是mac,用的iTerm2的終端)的源碼,還真找到了幾個發(fā)送SIGHUP信號的代碼
看名字PTYTask就能猜到了,這應(yīng)該是一個seesion任務(wù),于是進(jìn)到代碼里看到主要是有兩個方法有發(fā)送SIGHUP信號給子進(jìn)程,分別是dealloc和stop,其中stop會通過sendSignal函數(shù)給子進(jìn)程發(fā)送SIGHUP信號。
對于我這種比較喜歡自虐的人,一般會想怎么就確定這個就是我要找的代碼,之前從沒有寫過Object-C的代碼,想著是否有個類似java的jmap的工具可以讓我看內(nèi)存里的對象的情況,然而臨時沒找到,不過偶然發(fā)現(xiàn)mac自帶的Activity工具就能看到一些跡象,于是在Activity里找到了iTerm2進(jìn)程,然后對其內(nèi)存數(shù)據(jù)進(jìn)行了采樣,看能否抓到類似PTYTask. dealloc或者stop的調(diào)用棧,可是比較難模擬,因為存在時間差,點擊采樣的時候,很快就結(jié)束了,我還沒來得及關(guān)閉session。在看采樣報告的時候偶然看到了/usr/bin/sample的命令,原來Activity是采用這個命令進(jìn)行采樣的,于是摸索了一把,真能搞起來,采樣的時間可以自定義,間隔是1ms一次,這樣可以讓我有充足的時間來操作了,于是在采樣開啟之后,不斷地開一個session,起一個進(jìn)程,然后close,重復(fù)做了好幾次,結(jié)束采樣之后看采樣的輸出,還真的就抓到了PTYTask.stop的調(diào)用棧
這也就驗證了我close session的時候確實會給對應(yīng)的子進(jìn)程發(fā)送SIGHUP的信號。
那到此為止我們可以確認(rèn)的是
- 進(jìn)程退出是因為收到了信號SIGHUP
- 而SIGHUP的發(fā)生是因為終端Session Close
那到底是不是這種情況呢?
重新復(fù)盤問題現(xiàn)場
這個貌似不太可能,因為我們的shell腳本里執(zhí)行java的時候都會帶上&,這樣進(jìn)程就會后臺運行,不會出現(xiàn)這種session的問題。看了下腳本,確實是帶上了&的,自己也模擬了幾遍,在一個shell里調(diào)用帶有&的java命令,關(guān)閉終端java進(jìn)程并不會退出。難道是因為同事的終端配置和我的不一樣?后來要同事發(fā)了它的iTerm2里的seesion的配置給我看了下,和我的完全一樣,這就挺奇怪了。
于是再回過來看看之前的幾次進(jìn)程消失時候的日志(我要同事有保留),看到那幾個進(jìn)程退出的時間點,分別是
- 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那會應(yīng)該是快下班了,或者那會正好從上海趕車回杭州,于是問了下那個點同事是不是準(zhǔn)備回杭州了,同事說那會確實合上電腦準(zhǔn)備趕車回杭州,于是我接著問其他幾個時間是不是差不多也是合上電腦的時間,結(jié)果還真是那么巧,既然這樣,那說明我們的判斷方向是正確的了。
水落石出
后面突然發(fā)現(xiàn)同事修改過這個啟動腳本,在腳本的***加了行命令
- java xxxx &
- cd $DIR_LOG && tail -f common-*.log
難道是這個命令搞的鬼?
突然想起一個問題來,父子進(jìn)程的問題,假如說當(dāng)我們在shell里加了&跑的話,當(dāng)父進(jìn)程跑完之后,會直接將其掛到init進(jìn)程下面,也就是你通過ps -ef去看它的父進(jìn)程會是1號進(jìn)程,但是如果原來的父進(jìn)程沒有跑完,那其父進(jìn)程仍然會是原來的進(jìn)程,所以當(dāng)我們執(zhí)行這個腳本的時候,一直被執(zhí)行tail等待日志輸出,這樣一來,如果我們將當(dāng)前窗口關(guān)閉了,那就意味著父進(jìn)程會退出,然后給子進(jìn)程發(fā)送SIGHUP的信號,于是導(dǎo)致java進(jìn)程退出,但是如果我們在tail日志過程中ctrl c了,那java進(jìn)程會過繼給init進(jìn)程,因此此時當(dāng)我們再關(guān)閉窗口的時候也不會給其發(fā)送SIGHUP的信號了。
經(jīng)過驗證果然如此,至此這個消失的進(jìn)程終于得到了解釋,嗯,好在不是我們代碼的問題,值得欣慰,畢竟我們的代碼是要在客戶那邊運行的,必須要保證耗穩(wěn)定性。
【本文是專欄作者李嘉鵬的原創(chuàng)文章,轉(zhuǎn)載請通過微信公眾號(你假笨,id:lovestblog)聯(lián)系作者本人獲取授權(quán)】
戳這里,看該作者更多好文
本文名稱:進(jìn)程無故消失的破案歷程
瀏覽地址:http://m.fisionsoft.com.cn/article/dphjhsp.html


咨詢
建站咨詢
