技术文章 - CS233022
Windchill 数据库中的 IndexQueue1 和 IndexQueue2 出现死锁
已修改: 06-Jan-2025
适用于
- FlexPLM 10.2 M030 to 12.0
- Windchill PDMLink 10.2 M030-CPS07 to 12.1
说明
- IndexQueue1 或 IndexQueue2 由于 SQL 异常在 BackgroundMethodServer 日志中生成集群堆栈
- 由于 IndexQueue，队列被阻塞/变慢
- 队列在执行和就绪状态下被阻塞
- 一个 IndexQueue 将具有wt.pds.SQLDatabasePds.handleSQLException ：
"IndexQueue2.PollingThread" Id=181 prio=5 RUNNABLE (in native)
Blocked (cnt): 22653; Waited (cnt): 23359
CPU nanos: 325531250000; User nanos: 308593750000; Bytes allocated: 129579637296
Method context: 4eihtrmk;jrf0wyi1;3980;5ydi2x;881070; DB session: 190
% of 1 CPU used by context: 2.9146476775255348 (46875000/1608256132); Bytes allocated by context: 13757424
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at wt.util.WrappedSocket$Input.read(WrappedSocket.java:379)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
- locked java.io.BufferedInputStream@64780d
at java.io.DataInputStream.readByte(DataInputStream.java:265)
at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:222)
at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:161)
at com.sun.jmx.remote.internal.PRef.invoke(Unknown Source)
at javax.management.remote.rmi.RMIConnectionImpl_Stub.invoke(Unknown Source)
at javax.management.remote.rmi.RMIConnector$RemoteMBeanServerConnection.invoke(RMIConnector.java:1020)
at javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:298)
at com.sun.proxy.$Proxy170.getAttributesFromAllClusterMethodServers(Unknown Source)
at wt.util.jmx.GetClusterStacks.outputClusterStacks(GetClusterStacks.java:75)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at wt.pds.SQLDatabasePds.handleSQLException(SQLDatabasePds.java:1222)
at wt.pds.SQLDatabasePds.processSQLException(SQLDatabasePds.java:4132)
at wt.pds.SQLDatabasePds.insertList(SQLDatabasePds.java:3237)
at wt.pds.SQLDatabasePds.insert(SQLDatabasePds.java:306)
at wt.pom.PersistentObjectManager.insert(PersistentObjectManager.java:2404)
at wt.pom.PersistentObjectManager.insertUpdate(PersistentObjectManager.java:2322)
at wt.pom.PersistentObjectManager.insert(PersistentObjectManager.java:598)
at wt.fc.StandardPersistenceManager$1.doMultiOperation(StandardPersistenceManager.java:1673)
at wt.fc.WTCollectionRetrySingleProcessor.executeWithRetry(WTCollectionRetrySingleProcessor.java:162)
at wt.fc.WTCollectionRetrySingleProcessor.execute(WTCollectionRetrySingleProcessor.java:87)
at wt.fc.StandardPersistenceManager.insert(StandardPersistenceManager.java:1694)
at wt.fc.StandardPersistenceManager.store(StandardPersistenceManager.java:712)
at wt.fc.StandardPersistenceManager.store(StandardPersistenceManager.java:1091)
at wt.fc.StandardPersistenceManager.save(StandardPersistenceManager.java:928)
at sun.reflect.GeneratedMethodAccessor486.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at wt.services.ServiceFactory$ServerInvocationHandler.invoke(ServiceFactory.java:399)
at com.sun.proxy.$Proxy11.save(Unknown Source)
at wt.index.IndexStatusHelper.updateIndexerSet(IndexStatusHelper.java:217)
at wt.index.AbstractIndexServiceDelegate.index(AbstractIndexServiceDelegate.java:466)
at wt.index.IndexingServiceImpl.processIndexRequest(IndexingServiceImpl.java:280)
at wt.index.StandardIndexPolicyManager.processIndexRequest(StandardIndexPolicyManager.java:387)- 而另一个 IndexQueue 将具有wt.index.IndexStatusHelper.updateIndexerSet ：
"IndexQueue1.PollingThread" Id=191 prio=5 RUNNABLE (in native)
Blocked (cnt): 22417; Waited (cnt): 23112
CPU nanos: 326984375000; User nanos: 311640625000; Bytes allocated: 129347105296
Method context: 4eihtrmk;jrf0wyi1;3980;5ydi2x;881069; DB session: 177
% of 1 CPU used by context: 1.9430641127701833 (31250000/1608284554); Bytes allocated by context: 12813432
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at oracle.net.ns.Packet.receive(Packet.java:311)
at oracle.net.ns.DataPacket.receive(DataPacket.java:105)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:305)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:249)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:171)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:89)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:123)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:79)
at oracle.jdbc.driver.T4CMAREngineStream.unmarshalUB1(T4CMAREngineStream.java:426)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:390)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:249)
at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:566)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:215)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:58)
at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:943)
at oracle.jdbc.driver.OraclePreparedStatement.executeForRowsWithTimeout(OraclePreparedStatement.java:10932)
at oracle.jdbc.driver.OraclePreparedStatement.executeBatch(OraclePreparedStatement.java:11043)
- locked oracle.jdbc.driver.T4CConnection@706d819c
at oracle.jdbc.driver.OracleStatementWrapper.executeBatch(OracleStatementWrapper.java:244)
at wt.pds.SQLDatabasePds.insertList(SQLDatabasePds.java:3201)
at wt.pds.SQLDatabasePds.insert(SQLDatabasePds.java:306)
at wt.pom.PersistentObjectManager.insert(PersistentObjectManager.java:2404)
at wt.pom.PersistentObjectManager.insertUpdate(PersistentObjectManager.java:2322)
at wt.pom.PersistentObjectManager.insert(PersistentObjectManager.java:598)
at wt.fc.StandardPersistenceManager$1.doMultiOperation(StandardPersistenceManager.java:1673)
at wt.fc.WTCollectionRetrySingleProcessor.executeWithRetry(WTCollectionRetrySingleProcessor.java:162)
at wt.fc.WTCollectionRetrySingleProcessor.execute(WTCollectionRetrySingleProcessor.java:87)
at wt.fc.StandardPersistenceManager.insert(StandardPersistenceManager.java:1694)
at wt.fc.StandardPersistenceManager.store(StandardPersistenceManager.java:712)
at wt.fc.StandardPersistenceManager.store(StandardPersistenceManager.java:1091)
at wt.fc.StandardPersistenceManager.save(StandardPersistenceManager.java:928)
at sun.reflect.GeneratedMethodAccessor486.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at wt.services.ServiceFactory$ServerInvocationHandler.invoke(ServiceFactory.java:399)
at com.sun.proxy.$Proxy11.save(Unknown Source)
at wt.index.IndexStatusHelper.updateIndexerSet(IndexStatusHelper.java:217)
at wt.index.AbstractIndexServiceDelegate.index(AbstractIndexServiceDelegate.java:466)
at wt.index.IndexingServiceImpl.processIndexRequest(IndexingServiceImpl.java:280)
at wt.index.StandardIndexPolicyManager.processIndexRequest(StandardIndexPolicyManager.java:387)
- Oracle 警报日志表明发生死锁：
ORA-00060: Deadlock detected. See Note 60.1 at My Oracle Support for Troubleshooting ORA-60 Errors. More info in file E:\ORACLE\diag\rdbms\wind\wind\trace\wind_ora_864.trc.
- Oracle 跟踪文件中的会话 ID 在 BackgroundMethodServer 日志中匹配数据库会话
- wind_ora_864.trc显示会话 ID 177和190处于死锁状态：
Deadlock graph:
---------Blocker(s)-------- ---------Waiter(s)---------
Resource Name process session holds waits process session holds waits
TX-000E0010-0001DD9C-00000000-00000000 109 190 X 61 177 S
TX-000D0006-0001BC1C-00000000-00000000 61 177 X 109 190 S - BackgroundMethodServer 日志显示IndexQueue1的DB 会话：177 ：
"IndexQueue1.PollingThread" Id=191 prio=5 RUNNABLE (in native)
Blocked (cnt): 22417; Waited (cnt): 23112
CPU nanos: 326984375000; User nanos: 311640625000; Bytes allocated: 129347105296
Method context: 4eihtrmk;jrf0wyi1;3980;5ydi2x;881069; DB session: 177
BackgroundMethodServer log shows DB session: 190 for IndexQueue2:
"IndexQueue2.PollingThread" Id=181 prio=5 RUNNABLE (in native)
Blocked (cnt): 22653; Waited (cnt): 23359
CPU nanos: 325531250000; User nanos: 308593750000; Bytes allocated: 129579637296
Method context: 4eihtrmk;jrf0wyi1;3980;5ydi2x;881070; DB session: 190- Oracle 跟踪文件显示两个死锁会话当前正在运行相同的 INSERT 语句：
INSERT INTO IndexStatus(classnameA2A2,updateCountA2,batchId,coreName,errorDesc,indexRequestId,indexedObject,indexerSet,status,markForDeleteA2,ufid,verified,updateStampA2,createStampA2,modifyStampA2,idA2A2) VALUES ('wt.index.IndexStatus',1,:1 ,:2 ,:3 ,:4 ,:5 ,:6 ,:7 ,:8 ,:9 ,:10 ,:11 ,:12 ,:13 ,:14 )
这是文章 233022 的 PDF 版本，可能已过期。最新版本 CS233022