命令描述

jstack:用來檢視指定java程序的jvm執行緒棧資訊

使用方法

jstack -[operation] pid
其中operation：
-F:當 jstack pid沒有響應時，使用-F強制dump執行緒資訊
-m:列印java執行緒棧和本地執行緒棧
-l:長期監聽，列印鎖資訊

結果描述

使用jstack pid dump出來的執行緒資訊如下：

"pool-24-thread-85" #22861 prio=5 os_prio=0 tid=0x00007fdae45fc800 nid=0x2bba waiting on condition [0x00007fd94ca8a000]
 

   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x000000070f27ab40> (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:1067)
    at java.util.concurrent.ThreadPoolExecutor
 
.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"Ice.ThreadPool.Client-252" #22835 daemon prio=5 os_prio=0 tid=0x00007fda5804b800 nid=0x2769 runnable [0x00007fd9504fc000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x000000070ba2ae50> (a sun.nio.ch.Util$2)
    - locked <0x000000070ba2ae68> (a java.util.Collections$UnmodifiableSet)
    - locked <0x000000070b3193f0> (a sun.nio.ch.EPollSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
    at IceInternal.Selector.select(Selector.java:258)
    at IceInternal.ThreadPool.run(ThreadPool.java:319)
    at IceInternal.ThreadPool.access$300(ThreadPool.java:12)
    at IceInternal.ThreadPool$EventHandlerThread.run(ThreadPool.java:643)
    at java.lang.Thread.run(Thread.java:745)

其中包含執行緒基本資訊和執行緒棧資訊，從平時暴露的問題來看主要關注的在兩個方面
（1）執行緒中的死鎖情況：deadlock
（2）棧中呼叫的方法情況，尤其當發現大部分的執行緒棧在呼叫某個特定方法的時候，這個方法基本可以確定是有問題的

案例

這個案例來自公司日常開發運維中遇到的問題，感謝親愛的同事們的分析和幫助！

開發過程中沒有遇到過通過執行緒棧排查死鎖問題，但是排查慢介面的問題遇到過幾次。

首先講一下現象：

某天客服小妹反饋線上服務不可用了，好捉急

問題排查

1. 看下郵件，是否有報警。因為我們是web服務，如果埠掛了或者有特別的多5XX都會收到報警郵件-false
2. 訪問下線上服務，確認務是不是真的不可用了 -true
3. 登入到一臺線上伺服器，看下線上日誌，是不是有報錯。-false（因為這邊是分散式部署，當時訪問的伺服器確實沒有問題）
4. 然後趕緊開啟其他的伺服器日誌，忽然發現日誌根本沒在動，ps一下程序，發現程序沒了！沒了！
5. netstat一下埠，發現埠還在。但是狀態都是TIME_WAIT
   
6. 重啟掛掉的服務
7. 重啟後使用jstack檢視執行緒棧資訊：
   
   從執行緒棧資訊可以看到棧裡面執行cacheManager.getResource()和exists()方法特別多，基本可以定位問題在這裡。
8. 於是去對應的方法裡面看了一下，並沒有看出什麼端倪。此處只是獲取redis連線， 而exists也只是執行了一下redis的exists方法。但是這個檔案確實當天被改動並上線過。

 public Jedis getResource() {
        Jedis jedis = null;
        try {
            jedis = jedisPool.getResource();
        } catch (Exception e) {
            LOGGER.error("Failed to get jedis resource, reason is " + e.getMessage());
        }
        return jedis;
    }

1. CacheManager這個檔案從之前手動初始化單例的方式，換成了用spring管理，並用註解注入。最開始懷疑是初試化方式不對，有可能在不斷的建立redis連線，因為建立連線的部分寫在後遭方法裡面，但是嘗試了幾次發現，這個都早方法並不會呼叫多次。

        public CacheManager() {
        JedisPoolConfig config = new JedisPoolConfig();
        AppConfigs appConfigs = AppConfigs.getInstance();
        config.setMinIdle(Integer.parseInt(appConfigs.get(KEY_POOL_MIN_IDLE)));
        config.setMaxIdle(Integer.parseInt(appConfigs.get(KEY_POOL_MAX_IDLE)));
        this.jedisPool = new JedisPool(config,
                appConfigs.get(KEY_SERVER_HOST),
                Integer.parseInt(appConfigs.get(KEY_SERVER_PORT)));
    }

1. 然後對比了一下修改前後的檔案發現了這樣的兩處程式碼：

   修改前的程式碼：

修改後的程式碼：

這樣修改後redis連線不被回收！導致連線發生瞬時暴增。

總結

redis連線瞬時暴增後getResource()方法超時嚴重，請求得不到釋放。伺服器端tomcat的最大執行緒數配置是 maxThreads=1000（預設200），佇列中允許的請求數是：acceptCount=500（預設10）。導致幾乎所有的請求都阻塞在getResource()上，tomcat處理能力達到了極限。由於我們所有的服務都通過nginx代理，最終新進來的請求會被nginx直接返回而不能到達tomcat端，瀏覽器端顯示502。

至於服務程序為什麼沒了，我想是因為這個服務過於消耗資源被作業系統kill了。