案例解析:線程池使用不當導致的系統崩潰


前幾天,發現一台阿里雲服務器上的Web服務不可用。遠程SSH登錄不上,嘗試幾次登錄上去之后,執行命令都顯示

-bash: fork: Cannot allocate memory

一看以為是內存泄漏導致溢出。因為執行不了任何命令, 只能通過控制台重啟服務器恢復服務。 

 

初步排查

服務恢復后,查看系統日志,linux系統日志路徑/var/log/messages,可通過journalctl命令查看,如

journalctl --since="2019-06-12 06:00:00" --until="2019-06-12 10:00:00"

可查看since之后,until之前時間段的日志。除了發現crond[14954]: (CRON) CAN'T FORK (do_command): Cannot allocate memory 這個錯誤日志,未見其它異常(下面的sshd[10764]: error: fork: Cannot allocate memory應是ssh登錄執行命名失敗的日志)

linux-log

通過阿里雲-雲監控-主機監控查看內存使用率指標,這段時間內,內存使用率一直在40%以下,基本可排除內存溢出的可能。

通過搜索查閱到進程數超過操作系統限制可能導致bash: fork: Cannot allocate memory的報錯(參考: https://blog.csdn.net/wangshuminjava/article/details/80603847 )。

通過ps -eLf|wc -l查看當前進程線程數(ps -ef只打印進程,ps -eLf會打印所有的線程), 只有1000多個,故障時刻系統到底運行了多少線程已無從得知,只能持續跟進監測。

問題定位

幾天后,再次通過ps -eLf|wc -l查看,發現線程數已達16000多個。直接執行ps -eLf可看到大量tomcat進程所產生的線程,猜測是不是線程死鎖導致大量線程未完成一直hung在那里。

執行 jstack 進程號 > ~/jstack.txt 命令將進程所運行線程情況打印出來分析,發現大量的WAITING狀態的線程,如下

"pool-19-thread-1" #254 prio=5 os_prio=0 tid=0x00007f0b700a6000 nid=0x29a9 waiting on condition [0x00007f0b274df000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006ce3d8790> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

 

根據上述內容可看出線程在等一個條件,並且是在執行LinkedBlockingQueue.take方法的時候,查看該方法的java doc,當隊列為空時,該方法將會一直等待直到有元素可用。

/**
 * Retrieves and removes the head of this queue, waiting if necessary
 * until an element becomes available.
 *
 * @return the head of this queue
 * @throws InterruptedException if interrupted while waiting
 */
E take() throws InterruptedException;

  

詢問同事在哪里用到了LinkedBlockingQueue,同事回憶起不久前用線程池實現往阿里雲OSS服務通過追加的方式上傳文件功能,查看代碼后發現問題——線程池沒有關閉。為了使文件片段保存不存在錯亂,每次保存文件時,都new了一個線程池對象, 

ThreadPoolExecutor saveImgThreadPool = new ThreadPoolExecutor(1, 1, 0, TimeUnit.SECONDS, new LinkedBlockingQueue<>());

但處理完后, 沒有關閉這個線程池對象,這樣線程池仍會通過take方法去取等待隊列中是否還有未完成的線程任務,等待隊列為空時將會一直等待,這樣就導致大量的線程hung在這里了(基本是只要方法被調一次,就會產生一個hung住的線程)。 

延伸

  1. 線程狀態為“waiting for monitor entry”:
    意味着它 在等待進入一個臨界區 ,所以它在”Entry Set“隊列中等待。此時線程狀態一般都是 Blocked:
    java.lang.Thread.State: BLOCKED (on object monitor)

  2. 線程狀態為“waiting on condition”:
    說明它在等待另一個條件的發生,來把自己喚醒,或者干脆它是調用了 sleep(N)。此時線程狀態大致為以下幾種:
    java.lang.Thread.State: WAITING (parking):一直等那個條件發生(本文案例即為此種場景);java.lang.Thread.State: TIMED_WAITING (parking或sleeping):定時的,那個條件不到來,也將定時喚醒自己。

  3. 如果大量線程在“waiting for monitor entry”:可能是一個全局鎖阻塞住了大量線程。如果短時間內打印的thread dump 文件反映,隨着時間流逝,waiting for monitor entry 的線程越來越多,沒有減少的趨勢,可能意味着某些線程在臨界區里呆的時間太長了,以至於越來越多新線程遲遲無法進入臨界區。

  4. 如果大量線程在“waiting on condition”:可能是它們又跑去獲取第三方資源,尤其是第三方網絡資源,遲遲獲取不到Response,導致大量線程進入等待狀態。所以如果你發現有大量的線程都處在 Wait on condition,從線程堆棧看,正等待網絡讀寫,這可能是一個網絡瓶頸的征兆,因為網絡阻塞導致線程無法執行。也可能是如本文所提到的,由於程序編寫不當所致。





我的個人博客地址:http://blog.jboost.cn
我的頭條空間: https://www.toutiao.com/c/user/5833678517/#mid=1636101215791112
我的github地址:https://github.com/ronwxy
我的微信公眾號:jboost-ksxy

——————————————————————————————————————

微信公眾號
歡迎關注我的微信公眾號,及時獲取最新分享


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM