jstack診斷weblogic連線池滿的問題
阿新 • • 發佈:2019-02-05
1.節點現場告警,weblogic節點告警,且系統使用緩慢。
2.看weblogic日誌出現大量的錯誤日誌,連不上資料來源:
java.sql.SQLException: start() failed on resource 'CTDataSource_gg_domain': XAER_RMERR : A resource manager error has occured in the transaction branch
weblogic.transaction.internal.ResourceAccessException: Transaction has timed out when making request to XAResource 'CTDataSource_gg_domain'.
at weblogic.transaction.internal.XAResourceDescriptor.startResourceUse(XAResourceDescriptor.java:670)
at weblogic.transaction.internal.XAServerResourceInfo.start(XAServerResourceInfo.java:1230)
at weblogic.transaction.internal.XAServerResourceInfo.xaStart(XAServerResourceInfo.java:1164)
at weblogic.transaction.internal.XAServerResourceInfo.enlist(XAServerResourceInfo.java:285)
at weblogic.transaction.internal.ServerTransactionImpl.enlistResource(ServerTransactionImpl.java:522)
at weblogic.transaction.internal.ServerTransactionImpl.enlistResource(ServerTransactionImpl.java:449)
at weblogic.jdbc.jts.Driver.createLocalConnection(Driver.java:349)
at weblogic.jdbc.jts.Driver.connect(Driver.java:173)
at weblogic.jdbc.common.internal.RmiDataSource.getConnection(RmiDataSource.java:364)
3.以前都沒有見過這種錯誤。檢視weblogic console JDBC資料來源執行時統計資訊的幾個引數,發現連線池滿了。
4.連線池滿了,到底是什麼東西佔滿了,分析dump和jstack。在分析jstack上有突破,發現大量的執行緒blocked。
"[ACTIVE] ExecuteThread: '134' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f610808c000 nid=0x19a waiting for monitor entry [0x00007f5eb10cf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at weblogic.jdbc.wrapper.JTSConnection.internalRollback(JTSConnection.java:454)
- waiting to lock <0x00000007542f9bb0> (a weblogic.jdbc.wrapper.JTSConnection_oracle_jdbc_driver_T4CConnection)
at weblogic.jdbc.wrapper.JTSXAResourceImpl.rollback(JTSXAResourceImpl.java:71)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:1493)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:788)
at weblogic.transaction.internal.ServerSCInfo.startRollback(ServerSCInfo.java:875)
at weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2050)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3120)
at weblogic.transaction.internal.ServerTransactionImpl.access$100(ServerTransactionImpl.java:63)
at weblogic.transaction.internal.ServerTransactionImpl$1.run(ServerTransactionImpl.java:3355)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)
"[ACTIVE] ExecuteThread: '132' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f60e401a000 nid=0x703d waiting for monitor entry [0x00007f5eb12d1000]
java.lang.Thread.State: BLOCKED (on object monitor)
at weblogic.jdbc.wrapper.JTSConnection.internalRollback(JTSConnection.java:454)
- waiting to lock <0x00000007542f9bb0> (a weblogic.jdbc.wrapper.JTSConnection_oracle_jdbc_driver_T4CConnection)
at weblogic.jdbc.wrapper.JTSXAResourceImpl.rollback(JTSXAResourceImpl.java:71)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:1493)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:788)
at weblogic.transaction.internal.ServerSCInfo.startRollback(ServerSCInfo.java:875)
at weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2050)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3120)
at weblogic.transaction.internal.ServerTransactionImpl.access$100(ServerTransactionImpl.java:63)
at weblogic.transaction.internal.ServerTransactionImpl$1.run(ServerTransactionImpl.java:3355)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)
根據waiting to lock <0x00000007542f9bb0>搜尋,發現執行緒9持有:
"[ACTIVE] ExecuteThread: '9' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f6108006000 nid=0x53e waiting for monitor entry [0x00007f60d1fda000]
java.lang.Thread.State: BLOCKED (on object monitor)
at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:3896)
- waiting to lock <0x0000000703ccd180> (a oracle.jdbc.driver.T4CConnection)
at weblogic.jdbc.wrapper.JTSConnection.internalRollback(JTSConnection.java:460)
- locked <0x00000007542f9bb0> (a weblogic.jdbc.wrapper.JTSConnection_oracle_jdbc_driver_T4CConnection)
at weblogic.jdbc.wrapper.JTSXAResourceImpl.rollback(JTSXAResourceImpl.java:71)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:1493)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:788)
at weblogic.transaction.internal.ServerSCInfo.startRollback(ServerSCInfo.java:875)
at weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2050)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3120)
at weblogic.transaction.internal.ServerTransactionImpl.globalRollback(ServerTransactionImpl.java:2872)
at weblogic.transaction.internal.TransactionImpl$3.run(TransactionImpl.java:2000)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)
根據waiting to lock <0x0000000703ccd180> 搜尋,發現執行緒13持有,可以確定這個就是罪魁禍首,業務讀取大欄位:
"[STUCK] ExecuteThread: '13' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f6108009800 nid=0x46bd runnable [0x00007f60d1ad0000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at oracle.net.ns.Packet.receive(Packet.java:293)
at oracle.net.ns.DataPacket.receive(DataPacket.java:104)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:260)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:105)
at oracle.jdbc.driver.T4CMAREngine.getNBytes(T4CMAREngine.java:1504)
at oracle.jdbc.driver.T4C8TTILobd.unmarshalLobData(T4C8TTILobd.java:450)
at oracle.jdbc.driver.T4C8TTILob.readLOBD(T4C8TTILob.java:767)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:358)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:191)
at oracle.jdbc.driver.T4C8TTILob.read(T4C8TTILob.java:146)
at oracle.jdbc.driver.T4CConnection.getBytes(T4CConnection.java:2346)
- locked <0x0000000703ccd180> (a oracle.jdbc.driver.T4CConnection)
at oracle.sql.BLOB.getBytes(BLOB.java:331)
at oracle.sql.BLOB.getBytes(BLOB.java:217)
at oracle.jdbc.driver.T4CBlobAccessor.getBytes(T4CBlobAccessor.java:464)
at oracle.jdbc.driver.OracleResultSetImpl.getBytes(OracleResultSetImpl.java:708)
- locked <0x0000000703ccd180> (a oracle.jdbc.driver.T4CConnection)
at oracle.jdbc.driver.OracleResultSet.getBytes(OracleResultSet.java:398)
at weblogic.jdbc.wrapper.ResultSet_oracle_jdbc_driver_OracleResultSetImpl.getBytes(Unknown Source)
at com.gg.bpms.engine.deploy.model.DefinitionModelVOConvert.voConvert(DefinitionModelVOConvert.java:80)
.................................................................
2.看weblogic日誌出現大量的錯誤日誌,連不上資料來源:
java.sql.SQLException: start() failed on resource 'CTDataSource_gg_domain': XAER_RMERR : A resource manager error has occured in the transaction branch
weblogic.transaction.internal.ResourceAccessException: Transaction has timed out when making request to XAResource 'CTDataSource_gg_domain'.
at weblogic.transaction.internal.XAResourceDescriptor.startResourceUse(XAResourceDescriptor.java:670)
at weblogic.transaction.internal.XAServerResourceInfo.start(XAServerResourceInfo.java:1230)
at weblogic.transaction.internal.XAServerResourceInfo.xaStart(XAServerResourceInfo.java:1164)
at weblogic.transaction.internal.XAServerResourceInfo.enlist(XAServerResourceInfo.java:285)
at weblogic.transaction.internal.ServerTransactionImpl.enlistResource(ServerTransactionImpl.java:522)
at weblogic.transaction.internal.ServerTransactionImpl.enlistResource(ServerTransactionImpl.java:449)
at weblogic.jdbc.jts.Driver.createLocalConnection(Driver.java:349)
at weblogic.jdbc.jts.Driver.connect(Driver.java:173)
at weblogic.jdbc.common.internal.RmiDataSource.getConnection(RmiDataSource.java:364)
3.以前都沒有見過這種錯誤。檢視weblogic console JDBC資料來源執行時統計資訊的幾個引數,發現連線池滿了。
4.連線池滿了,到底是什麼東西佔滿了,分析dump和jstack。在分析jstack上有突破,發現大量的執行緒blocked。
"[ACTIVE] ExecuteThread: '134' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f610808c000 nid=0x19a waiting for monitor entry [0x00007f5eb10cf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at weblogic.jdbc.wrapper.JTSConnection.internalRollback(JTSConnection.java:454)
- waiting to lock <0x00000007542f9bb0> (a weblogic.jdbc.wrapper.JTSConnection_oracle_jdbc_driver_T4CConnection)
at weblogic.jdbc.wrapper.JTSXAResourceImpl.rollback(JTSXAResourceImpl.java:71)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:1493)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:788)
at weblogic.transaction.internal.ServerSCInfo.startRollback(ServerSCInfo.java:875)
at weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2050)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3120)
at weblogic.transaction.internal.ServerTransactionImpl.access$100(ServerTransactionImpl.java:63)
at weblogic.transaction.internal.ServerTransactionImpl$1.run(ServerTransactionImpl.java:3355)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)
"[ACTIVE] ExecuteThread: '132' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f60e401a000 nid=0x703d waiting for monitor entry [0x00007f5eb12d1000]
java.lang.Thread.State: BLOCKED (on object monitor)
at weblogic.jdbc.wrapper.JTSConnection.internalRollback(JTSConnection.java:454)
- waiting to lock <0x00000007542f9bb0> (a weblogic.jdbc.wrapper.JTSConnection_oracle_jdbc_driver_T4CConnection)
at weblogic.jdbc.wrapper.JTSXAResourceImpl.rollback(JTSXAResourceImpl.java:71)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:1493)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:788)
at weblogic.transaction.internal.ServerSCInfo.startRollback(ServerSCInfo.java:875)
at weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2050)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3120)
at weblogic.transaction.internal.ServerTransactionImpl.access$100(ServerTransactionImpl.java:63)
at weblogic.transaction.internal.ServerTransactionImpl$1.run(ServerTransactionImpl.java:3355)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)
根據waiting to lock <0x00000007542f9bb0>搜尋,發現執行緒9持有:
"[ACTIVE] ExecuteThread: '9' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f6108006000 nid=0x53e waiting for monitor entry [0x00007f60d1fda000]
java.lang.Thread.State: BLOCKED (on object monitor)
at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:3896)
- waiting to lock <0x0000000703ccd180> (a oracle.jdbc.driver.T4CConnection)
at weblogic.jdbc.wrapper.JTSConnection.internalRollback(JTSConnection.java:460)
- locked <0x00000007542f9bb0> (a weblogic.jdbc.wrapper.JTSConnection_oracle_jdbc_driver_T4CConnection)
at weblogic.jdbc.wrapper.JTSXAResourceImpl.rollback(JTSXAResourceImpl.java:71)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:1493)
at weblogic.transaction.internal.XAServerResourceInfo.rollback(XAServerResourceInfo.java:788)
at weblogic.transaction.internal.ServerSCInfo.startRollback(ServerSCInfo.java:875)
at weblogic.transaction.internal.ServerTransactionImpl.localRollback(ServerTransactionImpl.java:2050)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:3120)
at weblogic.transaction.internal.ServerTransactionImpl.globalRollback(ServerTransactionImpl.java:2872)
at weblogic.transaction.internal.TransactionImpl$3.run(TransactionImpl.java:2000)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)
根據waiting to lock <0x0000000703ccd180> 搜尋,發現執行緒13持有,可以確定這個就是罪魁禍首,業務讀取大欄位:
"[STUCK] ExecuteThread: '13' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f6108009800 nid=0x46bd runnable [0x00007f60d1ad0000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at oracle.net.ns.Packet.receive(Packet.java:293)
at oracle.net.ns.DataPacket.receive(DataPacket.java:104)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:260)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:105)
at oracle.jdbc.driver.T4CMAREngine.getNBytes(T4CMAREngine.java:1504)
at oracle.jdbc.driver.T4C8TTILobd.unmarshalLobData(T4C8TTILobd.java:450)
at oracle.jdbc.driver.T4C8TTILob.readLOBD(T4C8TTILob.java:767)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:358)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:191)
at oracle.jdbc.driver.T4C8TTILob.read(T4C8TTILob.java:146)
at oracle.jdbc.driver.T4CConnection.getBytes(T4CConnection.java:2346)
- locked <0x0000000703ccd180> (a oracle.jdbc.driver.T4CConnection)
at oracle.sql.BLOB.getBytes(BLOB.java:331)
at oracle.sql.BLOB.getBytes(BLOB.java:217)
at oracle.jdbc.driver.T4CBlobAccessor.getBytes(T4CBlobAccessor.java:464)
at oracle.jdbc.driver.OracleResultSetImpl.getBytes(OracleResultSetImpl.java:708)
- locked <0x0000000703ccd180> (a oracle.jdbc.driver.T4CConnection)
at oracle.jdbc.driver.OracleResultSet.getBytes(OracleResultSet.java:398)
at weblogic.jdbc.wrapper.ResultSet_oracle_jdbc_driver_OracleResultSetImpl.getBytes(Unknown Source)
at com.gg.bpms.engine.deploy.model.DefinitionModelVOConvert.voConvert(DefinitionModelVOConvert.java:80)
.................................................................