weblogic oracle.jdbc.driver.PhysicalConnection.rollback

朱雀 2022-06-05 23:17 217阅读 0赞

先是凌晨的时候中间件连数据库出了问题：  
org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (IO 错误: The Network Adapter could not establish the connection)  
at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1244) ~\[com.springsource.org.apache.commons.dbcp-1.2.2.osgi.jar:na\]  
at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:882) ~\[com.springsource.org.apache.commons.dbcp-1.2.2.osgi.jar:na\]  
at com.ic.core.util.IcDataSourceManager.getConnection(IcDataSourceManager.java:81) ~\[eic-core-1.0.6.jar:na\]  
  
然后出现连接不够用的情况：  
\#\#\#\#<2017-10-24 上午12时25分28秒 CST> <Info> <Common> <zc-sc-app04> <sys\_app04\_8001> <\[STUCK\] ExecuteThread: '61' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1508775928273> <BEA-000628> <Created "1" resources for pool "CTDataSource", out of which "1" are available and "0" are unavailable.>   
\#\#\#\#<2017-10-24 上午12时25分28秒 CST> <Info> <Common> <zc-sc-app04> <sys\_app04\_8001> <\[ACTIVE\] ExecuteThread: '29' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1508775928273> <BEA-000628> <Created "1" resources for pool "CTDataSource", out of which "1" are available and "0" are unavailable.>   
  
weblogic状态开始告警。  
  
上午10点钟的时候用jstack看到有事务在回滚，按理说事务回滚结束之后连接池会回收连接的，但等了两个小时看还是这个状态。  
"\[STUCK\] ExecuteThread: '6' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f1ad1c53000 nid=0x516e waiting for monitor entry \[0x00007f1a9d6d5000\]  
   java.lang.Thread.State: BLOCKED (on object monitor)  
at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:3896)  
\- waiting to lock <0x000000070d83a480> (a oracle.jdbc.driver.T4CConnection)  
at weblogic.jdbc.wrapper.Connection.forcedCleanup(Connection.java:153)  
at weblogic.common.resourcepool.ResourcePoolImpl.timeoutInactiveResources(ResourcePoolImpl.java:1953)  
at weblogic.common.resourcepool.ResourcePoolImpl.access$1500(ResourcePoolImpl.java:41)  
at weblogic.common.resourcepool.ResourcePoolImpl$ResourcePoolMaintanenceTask.timerExpired(ResourcePoolImpl.java:2675)  
at weblogic.timers.internal.TimerImpl.run(TimerImpl.java:273)  
at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:528)  
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)  
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)

检查了一下gv$session,并未发现有活动的连接，且当前的Weblogic连接都没有执行的SQL语句，我认为这是僵尸的线程，只能重启。

后来确定这是一个bug.

**Many Stuck Threads on JDBC Connection Rollback (文档 ID 1584478.1)**

## SYMPTOMS ##

1.  There are lots of messages like the following in the server log, and the server response is slow:  
    
    
    <WebLogicServer> <BEA-000337> <\[STUCK\] ExecuteThread: '5' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "611" seconds working on the request "weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl@1f12dec2", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace:  
        oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:3896)  
        weblogic.jdbc.wrapper.Connection.forcedCleanup(Connection.java:153)  
        weblogic.common.resourcepool.ResourcePoolImpl.timeoutInactiveResources(ResourcePoolImpl.java:1953)  
        weblogic.common.resourcepool.ResourcePoolImpl.access$1500(ResourcePoolImpl.java:41)  
        weblogic.common.resourcepool.ResourcePoolImpl$ResourcePoolMaintanenceTask.timerExpired(ResourcePoolImpl.java:2675)  
        weblogic.timers.internal.TimerImpl.run(TimerImpl.java:273)  
        weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:528)  
        weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)  
        weblogic.work.ExecuteThread.run(ExecuteThread.java:178)  
    >  
      
    <Error> <WebLogicServer> <BEA-000337> <\[STUCK\] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "631" seconds working on the request "weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl@20cb3eea", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace:  
        oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:3896)  
        weblogic.jdbc.wrapper.Connection.forcedCleanup(Connection.java:153)  
        weblogic.common.resourcepool.ResourcePoolImpl.timeoutInactiveResources(ResourcePoolImpl.java:1953)  
        weblogic.common.resourcepool.ResourcePoolImpl.access$1500(ResourcePoolImpl.java:41)  
        weblogic.common.resourcepool.ResourcePoolImpl$ResourcePoolMaintanenceTask.timerExpired(ResourcePoolImpl.java:2675)  
        weblogic.timers.internal.TimerImpl.run(TimerImpl.java:273)  
        weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:528)  
        weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)  
        weblogic.work.ExecuteThread.run(ExecuteThread.java:178)  
    >

## CAUSE ##

The issue depends on an uncontrollable timing sequence to occur, and also may involve a requirement that the datasource has been disabled or flushed (whether internally or manually) previously. The basic symptom is of a hanging thread, trying to do a rollback on a connection whose socket is in an externally-induced condition (maybe due to a firewall) that will relegate any standard JDBC call to hang indefinitely in a socket read. This issue is addressed by [Bug 10169939][].

[Bug 10169939]: https://support.oracle.com/epmos/faces/BugDisplay?parent=DOCUMENT&sourceId=1584478.1&id=10169939