[CALCITE-6209] Long queries are failing with "java.net.SocketTimeoutException: Read timed out" after 3 minutes

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: avatica-1.24.0
• Fix Version/s: avatica-1.25.0
• Component/s: avatica
• Labels: pull-request-available
• Assignee: Istvan Toth
• Reporter: Konstantin
• Created: 17/Jan/24 12:58
• Updated: 05/Apr/24 05:37
• Resolved: 12/Mar/24 11:36

Description

Long queries are failing with "java.net.SocketTimeoutException: Read timed out" after 3 minutes.
It's expected that they take more than 3 minutes and we need some way to increase timeout.
I tried to change it via http_connection_timeout property but it didn't help.
Looks like that property is related to connect timeout only, but not to request timeout.
I checked source code but didn't found any ways to change it there.
Looks like it's always using default timeout=3minutes.

Stack-trace:

org.jkiss.dbeaver.model.sql.DBSQLException: SQL Error: Error while executing SQL "SELECT count(1) FROM trace": java.net.SocketTimeoutException: Read timed out
	at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.executeStatement(JDBCStatementImpl.java:133)
	at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.executeStatement(SQLQueryJob.java:600)
	at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.lambda$2(SQLQueryJob.java:503)
	at org.jkiss.dbeaver.model.exec.DBExecUtils.tryExecuteRecover(DBExecUtils.java:190)
	at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.executeSingleQuery(SQLQueryJob.java:510)
	at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.extractData(SQLQueryJob.java:962)
	at org.jkiss.dbeaver.ui.editors.sql.SQLEditor$QueryResultsContainer.readData(SQLEditor.java:4130)
	at org.jkiss.dbeaver.ui.controls.resultset.ResultSetJobDataRead.lambda$0(ResultSetJobDataRead.java:123)
	at org.jkiss.dbeaver.model.exec.DBExecUtils.tryExecuteRecover(DBExecUtils.java:190)
	at org.jkiss.dbeaver.ui.controls.resultset.ResultSetJobDataRead.run(ResultSetJobDataRead.java:121)
	at org.jkiss.dbeaver.ui.controls.resultset.ResultSetViewer$ResultSetDataPumpJob.run(ResultSetViewer.java:5148)
	at org.jkiss.dbeaver.model.runtime.AbstractJob.run(AbstractJob.java:105)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)
Caused by: java.sql.SQLException: Error while executing SQL "SELECT count(1) FROM trace": java.net.SocketTimeoutException: Read timed out
	at org.apache.calcite.avatica.Helper.createException(Helper.java:56)
	at org.apache.calcite.avatica.Helper.createException(Helper.java:41)
	at org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:164)
	at org.apache.calcite.avatica.AvaticaStatement.execute(AvaticaStatement.java:218)
	at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.execute(JDBCStatementImpl.java:330)
	at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.executeStatement(JDBCStatementImpl.java:131)
	... 12 more
Caused by: java.lang.RuntimeException: java.net.SocketTimeoutException: Read timed out
	at org.apache.calcite.avatica.remote.AvaticaCommonsHttpClientImpl.send(AvaticaCommonsHttpClientImpl.java:155)
	at org.apache.calcite.avatica.remote.RemoteService.apply(RemoteService.java:36)
	at org.apache.calcite.avatica.remote.JsonService.apply(JsonService.java:140)
	at org.apache.calcite.avatica.remote.RemoteMeta$14.call(RemoteMeta.java:310)
	at org.apache.calcite.avatica.remote.RemoteMeta$14.call(RemoteMeta.java:307)
	at org.apache.calcite.avatica.AvaticaConnection.invokeWithRetries(AvaticaConnection.java:795)
	at org.apache.calcite.avatica.remote.RemoteMeta.fetch(RemoteMeta.java:306)
	at org.apache.calcite.avatica.MetaImpl$FetchIterator.moveNext(MetaImpl.java:1643)
	at org.apache.calcite.avatica.MetaImpl$FetchIterator.<init>(MetaImpl.java:1611)
	at org.apache.calcite.avatica.MetaImpl$FetchIterator.<init>(MetaImpl.java:1586)
	at org.apache.calcite.avatica.MetaImpl$FetchIterable.iterator(MetaImpl.java:1581)
	at org.apache.calcite.avatica.MetaImpl.createCursor(MetaImpl.java:98)
	at org.apache.calcite.avatica.AvaticaResultSet.execute(AvaticaResultSet.java:186)
	at org.apache.calcite.avatica.AvaticaConnection$1.execute(AvaticaConnection.java:669)
	at org.apache.calcite.avatica.remote.RemoteMeta$13.call(RemoteMeta.java:283)
	at org.apache.calcite.avatica.remote.RemoteMeta$13.call(RemoteMeta.java:263)
	at org.apache.calcite.avatica.AvaticaConnection.invokeWithRetries(AvaticaConnection.java:795)
	at org.apache.calcite.avatica.remote.RemoteMeta.prepareAndExecute(RemoteMeta.java:262)
	at org.apache.calcite.avatica.AvaticaConnection.prepareAndExecuteInternal(AvaticaConnection.java:677)
	at org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:157)
	... 15 more
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.base/sun.nio.ch.NioSocketImpl.timedRead(Unknown Source)
	at java.base/sun.nio.ch.NioSocketImpl.implRead(Unknown Source)
	at java.base/sun.nio.ch.NioSocketImpl.read(Unknown Source)
	at java.base/sun.nio.ch.NioSocketImpl$1.read(Unknown Source)
	at java.base/java.net.Socket$SocketInputStream.read(Unknown Source)
	at org.apache.hc.client5.http.impl.io.LoggingInputStream.read(LoggingInputStream.java:81)
	at org.apache.hc.core5.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:149)
	at org.apache.hc.core5.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
	at org.apache.hc.core5.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:247)
	at org.apache.hc.core5.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:54)
	at org.apache.hc.core5.http.impl.io.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:299)
	at org.apache.hc.core5.http.impl.io.HttpRequestExecutor.execute(HttpRequestExecutor.java:175)
	at org.apache.hc.core5.http.impl.io.HttpRequestExecutor.execute(HttpRequestExecutor.java:218)
	at org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManager$InternalConnectionEndpoint.execute(PoolingHttpClientConnectionManager.java:712)
	at org.apache.hc.client5.http.impl.classic.InternalExecRuntime.execute(InternalExecRuntime.java:216)
	at org.apache.hc.client5.http.impl.classic.MainClientExec.execute(MainClientExec.java:116)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.ConnectExec.execute(ConnectExec.java:188)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.ProtocolExec.execute(ProtocolExec.java:192)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.HttpRequestRetryExec.execute(HttpRequestRetryExec.java:96)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.ContentCompressionExec.execute(ContentCompressionExec.java:152)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.RedirectExec.execute(RedirectExec.java:115)
	at org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(ExecChainElement.java:51)
	at org.apache.hc.client5.http.impl.classic.InternalHttpClient.doExecute(InternalHttpClient.java:170)
	at org.apache.hc.client5.http.impl.classic.CloseableHttpClient.execute(CloseableHttpClient.java:106)
	at org.apache.calcite.avatica.remote.AvaticaCommonsHttpClientImpl.execute(AvaticaCommonsHttpClientImpl.java:163)
	at org.apache.calcite.avatica.remote.AvaticaCommonsHttpClientImpl.send(AvaticaCommonsHttpClientImpl.java:134)
	... 34 more

Issue Links

• links to: GitHub Pull Request #236