由ReentrantLock和JPA(spring.jpa.open-in-view)導致的死鎖問題原因分析。
問題在壓測過程中,發現服務經過一段時間壓測之後出現無響應,且無法自動恢復。
分析從上述問題表象中,猜測服務出現死鎖,導致所有執行緒都在等待獲取鎖,從而無法響應後續所有請求。
接下來透過jstack輸出執行緒堆疊資訊檢視,發現大量容器執行緒在等待資料庫連線
"XNIO-1 task-251" #375 prio=5 os_prio=0 tid=0x00007fec640cf800 nid=0x53ea waiting on condition [0x00007febf64c5000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000081565b80> (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 com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1899) at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1460) at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1255) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1235) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1225) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:90) at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:35) at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:106) at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:136) at org.hibernate.internal.SessionImpl.connection(SessionImpl.java:542)
檢視DruidDataSource原始碼,可以看出當前已經沒有可用的資料庫連線,所以執行緒等待。
DruidConnectionHolder takeLast() throws InterruptedException, SQLException { try { while (poolingCount == 0) { emptySignal(); // send signal to CreateThread create connection if (failFast && failContinuous.get()) { throw new DataSourceNotAvailableException(createError); } notEmptyWaitThreadCount++; if (notEmptyWaitThreadCount > notEmptyWaitThreadPeak) { notEmptyWaitThreadPeak = notEmptyWaitThreadCount; } try { // 當有新的連線被建立或者其他執行緒釋放連線,就會被喚醒 notEmpty.await(); // signal by recycle or creator } finally { notEmptyWaitThreadCount--; } notEmptyWaitCount++; if (!enable) { connectErrorCountUpdater.incrementAndGet(this); throw new DataSourceDisableException(); } } } catch (InterruptedException ie) { notEmpty.signal(); // propagate to non-interrupted thread notEmptySignalCount++; throw ie; } decrementPoolingCount(); DruidConnectionHolder last = connections[poolingCount]; connections[poolingCount] = null; return last; }
再檢視其他容器執行緒狀態,發現有8個執行緒在等待 0x000000008437e2c8 鎖,此鎖是ReentrantLock,說明ReentrantLock已經被其他執行緒持有。
分析可能是因為某種情況這8個執行緒沒有釋放資料庫連線,導致其他執行緒無法獲取資料庫連線(為什麼是8個呢,因為資料庫連線池採用預設配置,預設最大連線數為8)。
接下來繼續檢視ReentrantLock為什麼沒有正常的釋放,檢視當前持有該鎖的執行緒資訊,發現該執行緒持有了ReentrantLock鎖,但是又再等待資料庫連線。由於異常導致上一次獲取到鎖之後沒有釋放(沒有在finally程式碼塊中釋放鎖),但是僅僅是沒有釋放ReentrantLock並不會導致整個應用死鎖,因為該執行緒下一次執行請求的時候,它可以正常獲取到ReentrantLock(可重入性),然後如果正常釋放ReentrantLock,一切又會恢復正常。所以單純的ReentrantLock未釋放,並不會導致死鎖,問題的根本原因不是ReentrantLock沒有釋放鎖,肯定是其他問題導致資料庫連線沒有被正確的釋放。
透過上面的分析得知,有一個執行緒持有了ReentrantLock鎖,但是在等待資料庫連線,而另外8個執行緒持有了資料庫連線,卻在等待ReentrantLock鎖,產生死鎖。
但是正常情況下,當資料庫操作執行完成之後,執行緒應該會釋放資料庫連線,這裡顯然沒有釋放。由於我們這邊使用的JPA,所以猜測可能是JPA的問題。
聯想到在SpringBoot啟動日誌中發現JPA的警告日誌(使用過SpringJPA的同學應該都見過下面的日誌),具體如下
spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
猜想可能是由於這個配置問題,於是開始找Spring Data JPA相關文件。發現這個配置會導致請求執行完資料庫操作後,仍然持有資料庫連線。因為對於JPA(預設是Hibernate實現)來說,ToOne關係預設是立即載入,ToMany關係預設是懶載入。當我們透過JPA查詢到一個物件之後,可能會去呼叫ToMany關係對應實體的get方法,獲取對應實體集合,如果此時沒有Hibernate Session會報LazyInitializationException異常,所以預設情況下SpringBoot添加了一個攔截器,在請求開始的時候保持一個Session會話,請求執行完成之後才會關閉Session會話,同時釋放資料庫連線。
檢視 spring.jpa.open-in-view 對應的攔截器原始碼
public class OpenEntityManagerInViewInterceptor extends EntityManagerFactoryAccessor implements AsyncWebRequestInterceptor { @Override public void preHandle(WebRequest request) throws DataAccessException { EntityManagerFactory emf = obtainEntityManagerFactory(); if (TransactionSynchronizationManager.hasResource(emf)) { // ... } else { logger.debug("Opening JPA EntityManager in OpenEntityManagerInViewInterceptor"); try { // 建立EntityManager並繫結到當前執行緒 EntityManager em = createEntityManager(); EntityManagerHolder emHolder = new EntityManagerHolder(em); TransactionSynchronizationManager.bindResource(emf, emHolder); AsyncRequestInterceptor interceptor = new AsyncRequestInterceptor(emf, emHolder); asyncManager.registerCallableInterceptor(key, interceptor); asyncManager.registerDeferredResultInterceptor(key, interceptor); } catch (PersistenceException ex) { throw new DataAccessResourceFailureException("Could not create JPA EntityManager", ex); } } } @Override public void afterCompletion(WebRequest request, @Nullable Exception ex) throws DataAccessException { // 關閉EntityManager if (!decrementParticipateCount(request)) { EntityManagerHolder emHolder = (EntityManagerHolder) TransactionSynchronizationManager.unbindResource(obtainEntityManagerFactory()); logger.debug("Closing JPA EntityManager in OpenEntityManagerInViewInterceptor"); EntityManagerFactoryUtils.closeEntityManager(emHolder.getEntityManager()); } } @Override public void afterConcurrentHandlingStarted(WebRequest request) { // 解除繫結 if (!decrementParticipateCount(request)) { TransactionSynchronizationManager.unbindResource(obtainEntityManagerFactory()); } }}
結論由於沒有配置 spring.jpa.open-in-view (預設為true),JPA方法執行完成之後,並沒有釋放資料庫連線(需要等到請求執行完成才會釋放),而恰好由於異常導致ReentrantLock鎖沒有正確釋放,進而導致其他已經獲取到資料庫連線的執行緒無法獲取ReentrantLock鎖,其他執行緒也無法獲取到資料庫連線(其中就包含持有ReentrantLock鎖的執行緒),最終導致死鎖。修復的方法非常簡單,finally程式碼塊中釋放鎖,並且關閉 spring.jpa.open-in-view 配置(可選)。
對於 spring.jpa.open-in-view 這個配置大致存在兩種觀點,一種認為需要這個配置,它有利於提升開發效率,另一個部分人認為這個配置會影響到效能(Controller方法執行完成之後才釋放連線),造成資源的浪費。但是如果執行完資料庫操作就釋放連線的話,就無法透過get方法獲取ToMany關係對應的實體集合(或者獲取手動獲取,但顯然不合適)。
其實這兩種觀點沒有對錯,只不過需要根據業務實際情況作出選擇。官方可能出於這種考慮,才在使用者沒有主動配置 spring.jpa.open-in-view 的時候,在啟動的過程中打印出一條警告日誌,通知使用者關注此項配置,主動作出選擇。