JDK的sql設計不合理導致的驅動類初始化死鎖問題
- 2020 年 4 月 2 日
- 筆記
問題描述
當我們一個系統既需要mysql驅動，也需要oracle驅動的時候，在並發載入初始化這些驅動類的過程中產生死鎖的可能性非常大，下面是一個模擬的例子，對於Thread2的實現其實是jdk里java.sql.DriverService的邏輯，也是我們第一次調用java.sql.DriverManager.registerDriver註冊一個驅動實例要走的邏輯(jdk1.6下)，不過這篇文章是使用我們生產環境的一個系統的執行緒dump和記憶體dump為基礎進行分析展開的。
如果以上程式碼運行過程中發現有執行緒一直卡死在Class.forName的調用里，那麼說明問題已經重現了。
先上兩張圖
記憶體態執行緒堆棧
執行緒堆棧
存疑點
仔細看看上面的執行緒dump分析和記憶體dump分析里的執行緒分析模組，您可能會有如下兩個疑惑：
-
【為什麼執行緒[Thread-0]一直卡在Class.forName的位置】：這有點出乎意料，做一個類載入要麼找不到拋出ClassNotFoundException，要麼找到直接返回，為什麼會一直卡在這個位置呢？
-
【明明[Thread-0]註冊的是mysql驅動為什麼會去載入Odbc的驅動類】：通過[Thread-0]在棧上看倒數第二幀展開看到傳入Class.forName的參數是com.mysql.jdbc.Driver，然後展開棧上順序第二幀，看到傳入的參數是sun.jdbc.odbc.JdbcOdbcDriver，這意味著在對mysql驅動類做載入初始化的過程中又觸發了JdbcOdbc驅動類的載入
疑惑點解釋
疑惑二：
第一個疑惑我們先留著，先解釋下第二個疑惑，大家可以對照堆棧通過反編譯rt.jar還有ojdbc6-11.2.0.3.0.jar看具體的程式碼
驅動類載入過程簡要介紹:
當要註冊某個sql驅動的時候是通過調用java.sql.DriverManager.registerDriver來實現的(注意這個方法加了synchronized關鍵字，後面解釋第一個疑惑的時候是關鍵)，而這個方法在第一次執行過程中，會在當前執行緒classloader的classpath下尋找所有/META-INF/services/java.sql.Driver文件，這個文件在mysql和oracle驅動jar里都有，裡面寫的是對應的驅動實現類名，這種機制是jdk提供的spi實現，找到這些文件之後，依次使用Class.forName(driverClassName, true, this.loader)來對這些驅動類進行載入，其中第二個參數是true，意味著不僅僅做一次loadClass的動作，還會初始化該類，即調用包含靜態塊的< clinit >方法，執行完之後才會返回，這樣就解釋了第二個疑惑，在mysql驅動註冊過程中還會對odbc驅動類進行載入並初始化
感想:
其實我覺得這種設計有點傻，為什麼要乾和自己不相關的事情呢，畫蛇添足的設計，首先類初始化的開銷是否放到一起做並沒有多大區別，其次正由於這種設計導致了今天這個死鎖的發生
疑惑一：
現在來說第一個疑惑，為什麼會一直卡在Class.forName呢，到底卡在哪裡，於是再通過jstack -m 命令將jvm里的堆棧也列印出來，如下所示
我們看到其實正在做類的初始化動作，並且執行緒正在調用ObjectSynchronizer::waitUninterruptibly一直沒返回，在看這方法的調用者instanceKlass1::initialize_impl，我們找到源碼位置如下：
類的初始化過程:
當某個執行緒獲得機會對某個類進行初始化的時候(請看上面的Step 6)，會設置這個類的init_state屬性為being_initialized(如果初始化好了會設置為fully_initialized，異常的話會設置為initialization_error)，還會設置init_thread屬性為當前執行緒，在這個設置過程中是有針對這個類提供了一把互斥鎖的，因此當有別的執行緒進來的時候會被攔截在外面，如果設置完了，這把互斥鎖也釋放了，但是因為這個類的狀態被設置了，因此並發問題也得到了解決，當另外一個執行緒也嘗試初始化這個類的時候會判斷這個類的狀態是不是being_initialized，並且其init_thread不是當前執行緒，那麼就會一直卡在那裡，也就是此次執行緒dump的執行緒所處的狀態，正在初始化類的執行緒會調用< clinit >方法，如果正常結束了，那麼就設置其狀態為fully_initialized，並且通知之前卡在那裡等待初始化完成的執行緒，然他們繼續往下走(下一個動作就是再判斷下狀態，發現完成了就直接return了)
猜想:
在了解了上面的過程之後，於是我們猜測兩種可能
-
第一，這個類的狀態還是being_intialized，還在while循環里沒有跳出來
-
第二，事件通知機制出現了問題，也就是pthread_cond_wait和pthread_cond_signal之間的通訊過程出現了問題。
不過第二種可能性非常小，比較linux久經考驗了，那接下來我們驗證其實是第一個猜想
驗證：
我們通過GDB attach的方式連到了問題機器上(好在機器沒有掛)，首先我們要找到具體的問題執行緒，我們通過上面的jstack -m命令看到了執行緒ID是5738，然後通過info threads找到對應的執行緒，並得到它的序號14
然後通過thread 14切換到對應的執行緒，並通過bt看到了如下的堆棧，正如我們想像的那樣，正在做類的初始化，一直卡在那裡
我們通過f 6選擇第7幀，在通過disassemble反彙編該幀，也就是對instanceKlass::initialize_impl ()這個方法反彙編
從上面的注釋我們其實得出了，我們要看當前類的初始化狀態，那就是看eax暫存器偏移0xe0的位置的值，而eax其實就是ebp暫存器偏移0xfffffff4位置的值，於是我們通過如下地址記憶體查到得到是4
而4其實代表的就是being_initialized這個狀態，程式碼如下
從這於是我們驗證了第一個猜想，其實是狀態一直沒有變更，因此一直卡在那裡，為了更進一步確認這個問題，要是我們能找到該類的init_thread執行緒id就更清楚了，拿到這個ID我們就能看到這個執行緒棧，就知道它在幹什麼了，但是很遺憾，這個很難獲取到，至少我一直沒有找到辦法，因為執行緒ID在執行緒對象里一直沒有存，都是調用的os函數來獲取的，得換個思路。
突然發現instanceKlass.hpp程式碼中得知兩個屬性原來是相鄰的(init_state和init_thread)，於是斷定下一個地址的值就代表是這個執行緒對象了，但是其屬性何其多，找到想要的太不易了，最主要的是還擔心自己看的程式碼和伺服器上的jvm程式碼不一致，這樣更蛋疼了，於是繼續查看Thread.hpp中的JavaThread類，找到個關鍵字0xDEAD-2=0xDEAB,這個有可能是volatile TerminatedTypes _terminated屬性的值，於是把執行緒對象列印出來，果然查到了關鍵字0xDEAB
因此順著這個屬性繼續往上找，找到了_thread_state表示執行緒狀態的值（向上偏移三個字），0x0000000a，即10，然後查看程式碼知道原來執行緒是出於block狀態
JavaThreadState
這樣一來查看下執行緒dump，發現Thread-1正好處於BLOCKED狀態，也就是說Thread-1就是那個正在對mysql驅動類做初始化的執行緒，這說明Thread-0和Thread-1成功互鎖了
於是我們展開Thread-1，看到- waiting to lock <0x71ae2ec0> (a java.lang.Class for java.sql.DriverManager)，該執行緒正在等待java.sql.DriverManager類型鎖，而blocked在那裡，而這個類型鎖是被Thread-0執行緒持有的，從Thread-1這個執行緒堆棧來看它其實也是在做Class.forName動作，並且通過Thread-1,展開第四幀我們可以看到其正在對載入sun.jdbc.odbc.JdbcOdbcDriver
問題現場遐想:
於是我們大膽設想一個場景，Thread-1先獲取到初始化sun.jdbc.odbc.JdbcOdbcDriver的機會，然後在執行sun.jdbc.odbc.JdbcOdbcDriver這個類的靜態塊的時候調用DriverManager.registerDriver(new Driver());，而該方法之前已經提到了是會加同步鎖的，再想像一下，在這個這個靜態塊之前，並且設置了sun.jdbc.odbc.JdbcOdbcDriver類的初始化狀態為being_initialized之後，Thread-0這個執行緒執行到了卡在的那個位置，並且我們從其堆棧可以看出它已經持有了java.sql.DriverManager這個類型的鎖，因此這兩個執行緒陷入了互鎖狀態
解決方案
解決方案目前想到的是將驅動類的載入過程變成單執行緒載入，不存在並發情況就沒問題了
推薦閱讀：
