Execuse me for my poor English and any thoughts are welcome!
We are using eclipselink 2.x, oracle jdbc, weblogic 10.3.6.
One query is very slow with certain sql paramter, takes about 30s. Same query with sql paramter value changed on takes about one seconds.
While experiment these two sql in sql worksheet or toad, both performance are good, within one second.
Our DBA found that slow query from jdbc waits at event: SQL*Net message from client.
I did a jrockit fly record to get following thread dump, find that thread waits at
jrockit.net.SocketNativeIO.readBytesPinned(FileDescriptor, byte[], int, int, int) 30,079,897,532 27
It seems that database is waiting command from jdbc while jdbc is stuck at io.
Then I use wireshark to see whats happening on network, find it take about 5s between following two events:
no. time source destination
2003 14:51:52.086459000 databaseip weblogicip TCP 60 1521→60188 [ACK] Seq=991 Ack=2019 Win=17520 Len=0
4063 14:51:57.287431000 databaseip weblogicip TNS 245 Request, Data (6), Data
following is the waiting thread dump:
jrockit.net.SocketNativeIO.readBytesPinned(FileDescriptor, byte[], int, int, int) 30,079,897,532 27
jrockit.net.SocketNativeIO.socketRead(FileDescriptor, byte[], int, int, int) 30,079,897,532 27
java.net.SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int) 30,079,897,532 27
java.net.SocketInputStream.read(byte[], int, int) 30,079,897,532 27
java.io.BufferedInputStream.fill() 2,479,373,819 26
oracle.net.ns.Packet.receive() 30,079,897,532 1
oracle.net.ns.DataPacket.receive() 30,079,897,532 1
oracle.net.ns.NetInputStream.getNextPacket() 30,079,897,532 1
oracle.net.ns.NetInputStream.read(byte[], int, int) 30,079,897,532 1
oracle.net.ns.NetInputStream.read(byte[]) 30,079,897,532 1
oracle.net.ns.NetInputStream.read() 30,079,897,532 1
oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket() 30,079,897,532 1
oracle.jdbc.driver.T4CSocketInputStreamWrapper.read() 30,079,897,532 1
oracle.jdbc.driver.T4CMAREngine.unmarshalUB1() 30,079,897,532 1
oracle.jdbc.driver.T4CTTIfun.receive() 30,079,897,532 1
oracle.jdbc.driver.T4CTTIfun.doRPC() 30,079,897,532 1
oracle.jdbc.driver.T4C8Oall.doOALL(boolean, boolean, boolean, boolean, boolean, OracleStatement$SqlKind, int, byte[], int, Accessor[], int, Accessor[], int, byte[], char[], short[], int, DBConversion, byte[], InputStream[][], byte[][][], OracleTypeADT[][], OracleStatement, byte[], char[], short[], T4CTTIoac[], int[], int[], int[], NTFDCNRegistration) 30,079,897,532 1
oracle.jdbc.driver.T4CPreparedStatement.doOall8(boolean, boolean, boolean, boolean, boolean) 30,079,897,532 1
oracle.jdbc.driver.T4CPreparedStatement.executeForRows(boolean) 30,079,897,532 1
oracle.jdbc.driver.OracleStatement.executeMaybeDescribe() 30,079,897,532 1
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout() 30,079,897,532 1
oracle.jdbc.driver.OraclePreparedStatement.executeInternal() 30,079,897,532 1
oracle.jdbc.driver.OraclePreparedStatement.executeQuery() 30,079,897,532 1
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery() 30,079,897,532 1
weblogic.jdbc.wrapper.PreparedStatement.executeQuery() 30,079,897,532 1
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseCall, Statement, AbstractSession) 30,079,897,532 1
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(Call, AbstractRecord, AbstractSession) 30,079,897,532 1
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(Call, AbstractRecord, AbstractSession) 30,079,897,532 1
org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(Call, AbstractRecord, DatabaseQuery) 30,079,897,532 1
org.eclipse.persistence.sessions.server.ServerSession.executeCall(Call, AbstractRecord, DatabaseQuery) 30,079,897,532 1
org.eclipse.persistence.sessions.server.ClientSession.executeCall(Call, AbstractRecord, DatabaseQuery) 30,079,897,532 1
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCall) 30,079,897,532 1
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall() 30,079,897,532 1
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall() 30,079,897,532 1
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows() 30,079,897,532 1
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable() 30,079,897,532 1
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows() 30,079,897,532 1
org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery() 30,079,897,532 1
org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery() 30,079,897,532 1
org.eclipse.persistence.queries.DatabaseQuery.execute(AbstractSession, AbstractRecord) 30,079,897,532 1
org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(AbstractSession, AbstractRecord) 30,079,897,532 1
org.eclipse.persistence.queries.ReadAllQuery.execute(AbstractSession, AbstractRecord) 30,079,897,532 1
org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(UnitOfWorkImpl, AbstractRecord) 30,079,897,532 1
org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(DatabaseQuery, AbstractRecord) 30,079,897,532 1
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(DatabaseQuery, AbstractRecord, int) 30,079,897,532 1
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(DatabaseQuery, AbstractRecord) 30,079,897,532 1
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(DatabaseQuery, List) 30,079,897,532 1
org.eclipse.persistence.internal.jpa.EJBQueryImpl.executeReadQuery() 30,079,897,532 1
org.eclipse.persistence.internal.jpa.EJBQueryImpl.getResultList() 30,079,897,532 1
UPDATING:
After Database restart, the problem goes away.
But in our production environment, the problem will happen after several month run.