0x0 現(xiàn)象
系統(tǒng)環(huán)境：
springboot + mybatis + druid + postgresql + activeMQ
下午5點(diǎn)44分，組件阻塞，日志不斷報(bào)異常：
org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction;
nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 60000, active 40, maxActive 40, creating 0
at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:289)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:377)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:461)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:277)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
...
可以看到，數(shù)據(jù)庫活躍連接數(shù)為40，以達(dá)到最大值，嘗試獲取連接60s沒有成功獲取到！
0x1 排查
- 查看日志，發(fā)現(xiàn)報(bào)錯(cuò)信息；
- 進(jìn)入數(shù)據(jù)庫查看當(dāng)前連接及正在執(zhí)行的sql：
select * from pg_stat_activity;
發(fā)現(xiàn)有幾十個(gè)插入語句事務(wù)一直沒有結(jié)束（事務(wù)始終處于開啟狀態(tài)，沒有提交）
- 查看數(shù)據(jù)庫日志：
2019-02-16 18:43:27 HKT [73708] 10.66.174.60(52950) pes_pesdb pes_pesdb_user FATAL: terminating connection due to idle-in-transaction timeout
2019-02-16 18:43:27 HKT [73708] 10.66.174.60(52950) pes_pesdb pes_pesdb_user LOG: disconnection: session time: 1:01:08.089 user=pes_pesdb_user database=pes_pesdb host=10.66.174.60 port=52950
2019-02-16 18:43:33 HKT [12972] 10.66.174.60(51381) pes_pesdb pes_pesdb_user FATAL: terminating connection due to idle-in-transaction timeout
2019-02-16 18:43:33 HKT [12972] 10.66.174.60(51381) pes_pesdb pes_pesdb_user LOG: disconnection: session time: 1:02:13.416 user=pes_pesdb_user
數(shù)據(jù)庫事務(wù)超時(shí)，被pg強(qiáng)制關(guān)閉！
這就導(dǎo)致了一個(gè)嚴(yán)重的問題：數(shù)據(jù)庫連接被數(shù)據(jù)庫端強(qiáng)制關(guān)閉了，但是我們druid連接池不知道，所以后來那些阻塞事務(wù)都被強(qiáng)制終結(jié)后依然獲取不到連接！
- 查看對(duì)應(yīng)的阻塞sql，發(fā)現(xiàn)了問題的原因：
偽代碼：
//開啟事務(wù)
begin transaction;
//執(zhí)行插入語句
insert();
//同步發(fā)送mq消息
MqUtils.sendMessage("insert sucess");
//提交事務(wù)
commit();
這里，如果發(fā)送消息阻塞了，會(huì)導(dǎo)致這個(gè)事務(wù)一直無法提交，從而導(dǎo)致連接被占用，無法釋放！
5.進(jìn)入發(fā)送消息的方法sendMessage()查看：
private boolean isPersistent=true;
可以看到默認(rèn)是持久化發(fā)送消息。
我們到activeMQ官網(wǎng)看下關(guān)于消息同步異步發(fā)送機(jī)制：
The good news is that ActiveMQ sends message in async mode by default in several cases. It is only in cases where the JMS specification required the use of sync sending that we default to sync sending. The cases that we are forced to send in sync mode are when persistent messages are being sent outside of a transaction.
If you are not using transactions and are sending persistent messages, then each send is synch and blocks until the broker has sent back an acknowledgement to the producer that the message has been safely persisted to disk.
看到加粗的那行描述以及下方描述，可見，當(dāng)我們消息是持久化發(fā)送時(shí)，會(huì)使用同步阻塞機(jī)制進(jìn)行send message，只有當(dāng)broker返回確認(rèn)給發(fā)送者，才認(rèn)為消息發(fā)送成功。
這種情況下，如果mq出現(xiàn)了問題，導(dǎo)致消息無法接收到，那么send message方法會(huì)阻塞，此時(shí)如果在一個(gè)事務(wù)中執(zhí)行該方法，那么會(huì)導(dǎo)致該事務(wù)無法commit，從而導(dǎo)致連接被長時(shí)間占用，直至最后pg強(qiáng)制回收。
至此終結(jié)問題。
至此終結(jié)問題。
0xFF 總結(jié)
下次出現(xiàn)這個(gè)問題，八成就是有某些事務(wù)開啟后，邏輯上阻塞了，無法關(guān)閉導(dǎo)致的。要注意，發(fā)送消息這些操作異步執(zhí)行！
