Statement.setQueryTimeout doesn't work on Oracle 18c jdbc driver

user_1297972 0
Viewed 2634

We have a J2EE application on a payara 5.2020 server that executes a long running query (PL/SQL that executes for a couple of hours). To avoid a timeout exception, we use this sentence at StatementLevel:

statement.setQueryTimeout(0);

This works using Oracle jdbc drivers version 12c, but when we have migrated to Oracle 18c, and we changed the driver to the version 18c, the query execution stops after 15 minutes with this exception. The code works with Oracle 12 and Oracle 18 is the change in the driver's jar what brings up the problem. The problem has been reproduced in Linux and Windows machines:

2021-06-14T07:50:01.762+0200|SEVERE: java.sql.SQLRecoverableException: Error de E/S: Socket read interrupted
    at oracle.jdbc.driver.T4CCallableStatement.executeForRows(T4CCallableStatement.java:946)
    at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1136)
    at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3640)
    at oracle.jdbc.driver.T4CCallableStatement.executeInternal(T4CCallableStatement.java:1318)
    at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3752)
    at oracle.jdbc.driver.OracleCallableStatement.execute(OracleCallableStatement.java:4242)
    at oracle.jdbc.driver.OraclePreparedStatementWrapper.execute(OraclePreparedStatementWrapper.java:1079)
    at com.sun.gjc.spi.base.PreparedStatementWrapper.execute(PreparedStatementWrapper.java:532)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at com.sun.gjc.spi.jdbc40.ProfiledConnectionWrapper40$1.invoke(ProfiledConnectionWrapper40.java:437)
    at com.sun.proxy.$Proxy324.execute(Unknown Source)
    at org.apache.jsp.index_jsp.callPL(index_jsp.java:49)
    at org.apache.jsp.index_jsp._jspService(index_jsp.java:108)
    at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:111)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
    at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:411)
    at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:473)
    at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:377)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
    at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1636)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:259)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161)
    at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:757)
    at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:577)
    at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:158)
    at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:371)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:238)
    at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:520)
    at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:217)
    at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:182)
    at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:156)
    at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:218)
    at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
    at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
    at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
    at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
    at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
    at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
    at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
    at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.io.InterruptedIOException: Socket read interrupted
    at oracle.net.nt.TimeoutSocketChannel.handleInterrupt(TimeoutSocketChannel.java:262)
    at oracle.net.nt.TimeoutSocketChannel.read(TimeoutSocketChannel.java:184)
    at oracle.net.ns.NSProtocolNIO.doSocketRead(NSProtocolNIO.java:544)
    at oracle.net.ns.NIOPacket.readHeader(NIOPacket.java:234)
    at oracle.net.ns.NIOPacket.readPacketFromSocketChannel(NIOPacket.java:174)
    at oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:122)
    at oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:100)
    at oracle.net.ns.NIONSDataChannel.readDataFromSocketChannel(NIONSDataChannel.java:86)
    at oracle.jdbc.driver.T4CMAREngineNIO.prepareForUnmarshall(T4CMAREngineNIO.java:762)
    at oracle.jdbc.driver.T4CMAREngineNIO.unmarshalUB1(T4CMAREngineNIO.java:427)
    at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:394)
    at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:255)
    at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:610)
    at oracle.jdbc.driver.T4CCallableStatement.doOall8(T4CCallableStatement.java:249)
    at oracle.jdbc.driver.T4CCallableStatement.doOall8(T4CCallableStatement.java:82)
    at oracle.jdbc.driver.T4CCallableStatement.executeForRows(T4CCallableStatement.java:924)

It seems the transport layer has been migrated to java.nio and the method setQueryTimeout is no longer

Things We've tried:

  1. Setting the default Statement timeout to -1 in the JDBC Connection Pool Advanced Attributes screen in payara console.
  2. Trying to set the time directly in the connection with conn.setNetworkTimeout(Executors.newFixedThreadPool(1), 0) didn't make any effect.
  3. In different sources we have found that these properties below should affect the network timeout evaluation. We set them as JVM properties for payara startup (-Doracle.net.CONNECT_TIMEOUT=xxx) and as JDBC Connection Pool Properties, both cases with values 0 and -1. Didn't work in any case.
  • oracle.net.CONNECT_TIMEOUT
  • oracle.net.READ_TIMEOUT
  • oracle.jdbc.ReadTimeout

Sources:

enter image description here

4.- As we are accessing the DataSource through payara DataSource pool, we cannot cast the com.sun.gjc.spi.jdbc40.DataSource40 (class provided by payara) to an OracleDataSource, but we created the DataSorce programatically to set the connection properties as shown here and setting the properties seen in the image above but it doesn't work:

public static Properties oracleProperties() {
    // Already tried -1 and 0
    Properties properties = new Properties();
    properties.put("Oracle.net.CONNECT_TIMEOUT", 0);
    properties.put("Oracle.net.READ_TIMEOUT", 0);
    properties.put("Oracle.jdbc.ReadTimeout", 0);
    return properties;
}

public static OracleDataSource createDataSource() throws Exception {
    OracleDataSource ods = new OracleDataSource();
    ods.setURL("jdbc:oracle:thin:@itauc4602x:1521/BDExp");
    ods.setUser("enevac");
    ods.setPassword("enevac");
    ods.setDataSourceName("OracleXADataSource");
    ods.setLoginTimeout(0);
    // default connection properties to avoid timeoutException
    ods.setConnectionProperties(oracleProperties());
    return ods;
}
  1. Has anyone faced this problem, any idea on how to avoid the timeOut restriction?
  2. Why 15 minutes?, according to the reference, the default value for oracle.net.ReadTimeout is 10 minutes.

Update: To explain in more detail why I think the problem is in the driver and why I discard other possible origins of the exception, I assume the timeout can be raised from three sources:

  • Network timeout: I discard it cause I'm testing a payara server in my local machine against the development database, with no firewall in between.
  • Database server: the DBA has checked the Oracle net services configuration and there's no limit set that explains the 15 minutes cut. Besides, in these case, an SQLException would be expected with some kind of ORA-xxx error code.
  • JDBC: this can be set at connection level, statement level and transaction level. As I said at the beginning, the code works with oracle 12c drivers against Oracle 12 and Oracle 18 servers, it was the change of the driver's jar what make the code stop working.
oracle18c jdbc oracle java
2 Answers

Finally the problem was fixed configuring in the payara pool the "connectionProperties" custom property of the OracleDataSource. As @ibre5041 pointed, setting the property oracle.jdbc.javaNetNio=false changes the transport layer used by the driver and it starts working as the oracle 12c previous version.

According to Oracle reference, the OracleDataSource implementors can receive the connection properties as a java.util.Properties object.

Table 8-2 Oracle Extended Data Source Properties

  • Name: connectionProperties
  • Type: java.util.Properties
  • Description: Specifies the connection properties.

To set a multivalued property to the jdbc pool in the Payara Admin Console, you have to set the properties as (prop1=value1,prop2=value2), (Thank you again Ondro Mihályi). So in our case we set:

connectionProperties = (oracle.jdbc.ReadTimeout=0, oracle.jdbc.javaNetNio=false)

As a summary of what works and doesn't using Oracle 18c jdbc driver (every step tested separately)::

  • Setting timeout at statement level doesn't work:

    statement.setQueryTimeout(0)

  • Setting timeout at connection level, with -1 or 0, doesn't work:

    conn.setNetworkTimeout(Executors.newFixedThreadPool(1), timeout in ms)

  • Setting timeout properties programmatically in the java.util.connection using the OracleDataSource makes it work as indicated in the question.

  • Setting timeout properties as JVM properties makes it work if the limit is below 15min, but if you set a value > 15 minutes the exceptions is thrown, so setting to 0 or -1 has no effect:

So this makes the query stop after 10 secs: -Doracle.net.CONNECT_TIMEOUT=10000 -Doracle.net.READ_TIMEOUT=10000 -Doracle.jdbc.ReadTimeout=10000

But with this stops after 15 minutes: -Doracle.net.CONNECT_TIMEOUT=-1 -Doracle.net.READ_TIMEOUT=-1 -Doracle.jdbc.ReadTimeout=-1

  • Setting oracle.net.keepAlive=true as JVM property as @Nirmala suggested doesn’t work.
  • Setting oracle.jdbc.javaNetNio=false as JVM property as @ibre5041 makes it work. So it points to some problem with the java.nio transport layer.

Anyway, we opened a support issue to Oracle, cause the jdbc api statement.setQueryTimeout(0) should work without having to configure the datasource, I'll put the response when the case is closed.

user_12979720

The query execution could be stopped because of default tcp connection timeout. Can you set keepalive property "oracle.net.keepAlive" to “true” and verify?

user_43935940
Related