Why is my command not timing out (JDBC)?
When working with the Microsoft JDBC driver for SQL Server, handling query timeouts is usually a fairly straight-forward issue. The driver supports the java.sql.Statement.setQueryTimeout() method and setting a timeout value through code will take care of most single-query statements that we might want to issue.
The situation becomes more complicated when dealing with statement batches that contain multiple SQL queries, combine result sets with update counts and errors, or even combine DML and DDL statements. This situation typically occurs when executing stored procedures, since that's where we typically see these more complicated queries or batches.
(Another issue that we often encounter with these stored procedures is how to properly handle all the results coming back from SQL Server. Please see this blog entry for a discussion of this topic:
If such a stored procedure takes a significant amount of time to execute, we would still like to have the ability to time out this execution. However, in some scenarios it appears that the driver is ignoring the timeout value that the application specified and the query takes longer than expected to execute, or in extreme cases, the application appears to be hung indefinitely.
To understand why these issues occur, we have to consider some constraints that are in place:
- The Microsoft JDBC driver for SQL Server only applies the timeout value to the initial execute, executeQuery, and executeUpdate, according to the JDBC specification. Any subsequent Statement or ResultSet operations are not subject to this timeout value. For example, retrieving output parameters, getting additional ResultSets after the first one or getting update counts after the first one.
- Even if the application does not process all the results of a query batch or stored procedure, SQL Server still sends all result sets, update counts, errors, warnings, or connection state changes to the client. Since the driver is receiving and processing these results, it might appear to the application that the driver is not behaving correctly but it is in fact handling these messages from the server.
- SQL Server employs some buffering of data to utilize network bandwidth efficiently. This can appear to change behavior of queries depending on how large the result sets become.
Let us take the example of two very different stored procedures that appear similar in their behavior if we simply look at the parameter list:
create table TestTimeout1
(f1 int)
go
insert into TestTimeout1 values (1)
go
CREATE PROCEDURE SpTestTimeout1
@p1 int out
AS
begin
waitfor delay '00:00:10' -- simulate blocking in database
select * from TestTimeout1
set @p1 = 1
end
go
CREATE PROCEDURE SpTestTimeout2
@p1 int out
AS
begin
select * from TestTimeout1
declare @temp INTEGER
set @temp = 1
while(@temp<100000)
begin
update TestTimeout1 set f1= @temp
set @temp=@temp+1
end
select * from TestTimeout1
set @p1 = 1
end
go
These two stored procedures both return an output parameter so we might want to execute them by simply calling CallableStatement.execute() and then get the parameter using CallableStatement.getInt(). If we do that, however, the second stored procedure will not time out and our simple application will be stuck executing the entire stored procedure. While it might appear that the driver is not honoring the time out value, on further inspection we will see that the execute returns immediately but it's the getInt() method that will be executing until the stored procedure completes.
To handle these types of scenarios, we need to make sure that we process all the results of the query, as the above blog post illustrates, and combine this approach with also measuring the time it takes to process all these results. Doing so will handle the vast majority of issues that arise. This approach is also analogous to how ODBC programmers handle complicated query processing by using SQLMoreResults/SQLFetch to iterate through all results of their query before getting the output parameter.
The full code of the application that demonstrates these two approaches is listed below.
method1() executes the stored procedure in a simple manner and ignores all the intermediate results that SQL Server is sending.
method2() processes all the results and also times the progress of all these operations. At the end, if we exceed the amount of time we want to spend on this query, it calls Statement.cancel() to stop the execution of the query on the server. Without doing so, the Statement.close() would still have to process all the results coming from the SQL Server to ensure that the driver sees all the important tokens from the server so that it can track the state of the connection correctly. There will be some slight delay added to the timeout but we retain control of the execution.
import java.sql.*;
public class Timeout {
public static void method1(CallableStatement c, int timeout)
{
long start = System.currentTimeMillis();
long stop = 0;
try
{
c.setQueryTimeout(timeout);
System.out.println("Method1: Executing Callable statement");
c.execute();
System.out.println("Callable statement executed");
int p1 = c.getInt(1);
System.out.println("Parameter: " + p1);
} catch (SQLException e) {
System.out.println(e);
}
stop = System.currentTimeMillis();
System.out.println("Duration: " + (stop-start)/1000 + "s.");
}
public static void method2(CallableStatement c, int timeout)
{
ResultSet rs = null;
long start = System.currentTimeMillis();
long stop = 0;
boolean timedOut = false;
try
{
c.setQueryTimeout(timeout);
System.out.println("Method2: Executing Callable statement");
boolean isThereAresultSetNext = c.execute();
System.out.println("Callable statement executed");
int updateCounts = 0;
while (true)
{
stop = System.currentTimeMillis();
if ( (stop - start)/1000 > timeout) {
System.out.println("Timeout exceeded in code");
timedOut = true;
break;
}
rs = c.getResultSet();
int updateCount = c.getUpdateCount();
// If there are no more results or update counts, we're done
if (!isThereAresultSetNext && updateCount == -1)
{
System.out.println("No results and update count is -1");
break;
}
// Check to see if there is a ResultSet
if (rs != null)
{
System.out.println("Resultset obtained");
while (rs.next())
{
//Rudimentary result processing
System.out.println(rs.getString(1));
//break;
}
rs.close();
} // Otherwise, there will be an update count
else
{
updateCounts++;
if (1 == updateCounts || updateCounts % 10000 == 0) {
System.out.println("Update count = " + c.getUpdateCount() + ", iteration: " + updateCounts);
}
}
isThereAresultSetNext = c.getMoreResults();
}
if (!timedOut) {
int p1 = c.getInt(1);
System.out.println( "Parameter: " + p1);
} else {
c.cancel();
}
c.close();
}
catch (SQLException e)
{
System.out.println(e);
}
stop = System.currentTimeMillis();
System.out.println("Duration: " + (stop-start) /1000 + "s.");
}
public static void main(String[] args) throws Exception
{
Class.forName("com.microsoft.sqlserver.jdbc.SQLServerDriver");
Connection cn =
DriverManager.getConnection("jdbc:sqlserver://server..","uid","pwd");
int timeout = 5;
String sp1 = "{call SPTestTimeout1(?)}";
String sp2 = "{call SPTestTimeout2(?)}";
System.out.println(sp1);
CallableStatement c = cn.prepareCall(sp1);
c.registerOutParameter(1, java.sql.Types.INTEGER);
method1(c, timeout);
method2(c, timeout);
System.out.println(sp2);
c = cn.prepareCall(sp2);
c.registerOutParameter(1, java.sql.Types.INTEGER);
method1(c, timeout);
method2(c, timeout);
cn.close();
}
}
The output of this application shows that the first method fails to time out properly while the second method uses its internal timer to complete the execution. It also shows the intermediate results for the purposes of the demonstration but the application can choose to display or ignore the results as appropriate.
Here is the output of the application:
{call SPTestTimeout1(?)}
Method1: Executing Callable statement
com.microsoft.sqlserver.jdbc.SQLServerException: The query has timed out.
Duration: 5s.
Method2: Executing Callable statement
com.microsoft.sqlserver.jdbc.SQLServerException: The query has timed out.
Duration: 5s.
{call SPTestTimeout2(?)}
Method1: Executing Callable statement
Callable statement executed
Parameter: 1
Duration: 21s.
Method2: Executing Callable statement
Callable statement executed
Resultset obtained
99999
Update count = 1, iteration: 1
Update count = 1, iteration: 10000
Update count = 1, iteration: 20000
Update count = 1, iteration: 30000
Timeout exceeded in code
Duration: 6s.
One final note: There are some very rare scenarios where even this approach will not always time out. Some of these are somewhat academic in nature but for some real world scenarios, we might have to re-visit the design of the stored procedure in question to make sure the application can always time out.
Author : Kamil Sykora, SQL Developer Escalation Services, Microsoft