1. 程式人生 > >p6spy列印sql日誌執行緒不安全導致的生產問題

p6spy列印sql日誌執行緒不安全導致的生產問題

  首先說明下我這個標題可能起的不到位,其實我本次要介紹的是一次生產定位問題的思路及過程。

1.生產現象

   國慶前期釋出了一個很小版本,大家都以為沒什麼問題,可是釋出後生產出現了問題並且持續了兩個小時以上,現象如下: ERROR|org.hibernate.engine.jdbc.spi.SqlExceptionHelper|[SimpleAsyncTaskExecutor-52] Timeout: Pool empty. Unable to fetch a connection in 30 seconds, none available[size:150; busy:150; idle:0; lastwait:60000].

  最直接報錯就是生產應用程式獲取資料庫連線無法正常獲取,當時未進行定位問題的情況下只打印了執行緒棧快照,堆快照資訊未儲存,然後擴大資料庫連線,最後重啟,重啟後無問題(當晚未留,第天定位)。

2.執行緒dump檔案分析

這裡涉及到資訊保安問題,公司內網無法傳送資料,所以本地再現了下,執行緒棧資訊大致如下: 在這裡插入圖片描述   我們線上程棧統計了正在執行的執行緒正好是資料庫連線池的最大數目,這裡我們就開始懷疑HashMap高併發非執行緒安全導致,佔用資料庫連線無法釋放。由於沒有堆資訊進行佐證,我們無法石錘 但是這裡很明顯是p6spy列印sql日誌引起的問題,我們可以到它的官網進行求證https://github.com/p6spy/p6spy/pull/318/commits/bba79de399f862b416db9d476e43f3af33ef90f7

在這裡插入圖片描述 這裡很明顯進行了執行緒安全的改造處理。接下來我們需要做的就是升級p6spy版本號2.3.0以上 至此我們的問題基本可以說定位到了問題,但是我們還需要學會思考,大家知道HashMap高併發容易引起死迴圈,或者資料丟失,那麼我們遇到問題時如何證明執行緒無法結束是因為HashMap導致的死迴圈呢?

3.問題復現及驗證

1.復現HashMap死迴圈 這裡我參考了倉頡圖解系列文章的復現demo 程式碼如下:

package com.spring.test.deadmap;

import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.atomic.AtomicInteger;

public class HashMapThread extends Thread {
    private static AtomicInteger ai = new AtomicInteger(0);
    private static Map<Integer, Integer> map = new HashMap<Integer, Integer>(1);

    public void run() {
        while (ai.get() < 100000) {
            map.put(ai.get(), ai.get());
            ai.incrementAndGet();
        }
    }
}
package com.spring.test.deadmap;

public class Test {
    public static void main(String[] args) {
        HashMapThread hmt0 = new HashMapThread();
        HashMapThread hmt1 = new HashMapThread();
        HashMapThread hmt2 = new HashMapThread();
        HashMapThread hmt3 = new HashMapThread();
        HashMapThread hmt4 = new HashMapThread();
        hmt0.start();
        hmt1.start();
        hmt2.start();
        hmt3.start();
        hmt4.start();
    }
}

使用低版本jdk較容易復現死迴圈,多試幾次。 2.證明執行緒無法結束是因為HashMap存在環     我們需要藉助堆快照形成堆內例項dump檔案,藉助MAT進行分析當前HashMap.Entry[]陣列中的Entry連結串列是否存在迴圈引用 在這裡插入圖片描述 顯然我們當前未結束執行緒的持有HashMap中存在環引用。