High client usage when closing result set after huge query

[David-Engel]

This issue was brought up by a customer. I wanted to capture it in a GitHub issue in case others encounter it and need to know why the driver behaves the way it does.

Driver version

7.0.0

SQL Server version

SQL Server 2017

Client Operating System

Windows 10

JAVA/JVM version

JRE 10

Table schema

CREATE TABLE TestTable (TestColumn varchar(max));
create table testtable2 (testcolumn varchar(max))

declare @i int = 0
while @i < 10000
begin
insert into testtable2 (testcolumn) values
('xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx')
select @i = @i + 1
end

set @i = 0
while @i < 500
begin
insert into testtable (testcolumn) select testcolumn from testtable2
select @i = @i + 1
end

Problem description

Execute a SQL query that returns a large result set, but only read a few rows before doing connection.rollback()

1. Expected behavior:
   Rollback is executed, ResultSet is closed immediately (less than a second).
2. Actual behavior:
   ResultSet.close() is causing all rows to be fetched from the server and taking a long time to close.

Reproduction code

    System.out.println("Start " + new java.util.Date().toString());
    String connectionString = "jdbc:sqlserver://<server>:1433;databaseName=<DBname>;user=<username>;password=<password>";
    try (Connection conn = DriverManager.getConnection(connectionString)) {
        conn.setAutoCommit(false);
        try (Statement statement = conn.createStatement()) {
            ResultSet rs = statement.executeQuery("select TestColumn from TestTable");
            try {
                while (rs.next()) {
                    System.out.println(rs.getString(1));
                    throw new SQLException("Testing...");
                }
            } finally {
                System.out.println("Closing rs " + new java.util.Date().toString());
                rs.close();
                System.out.println("Rs closed " + new java.util.Date().toString());
            }
        } catch (SQLException se) {
            se.printStackTrace();
            conn.rollback();
            System.out.println("Rollback complete " + new java.util.Date().toString());
        }
    } catch (SQLException e) {
        e.printStackTrace();
    }
    System.out.println("Done " + new java.util.Date().toString());

Workaround

You can call statement.cancel() to abort processing of further results before calling rs.close(). This will have the effect of cancelling all result sets that might be following the first one being returned by the statement.

This behavior is by design and is not specific to the JDBC driver. All drivers that communicate with SQL Server must follow the TDS specification. A statement may return multiple result sets, whether it is multiple SELECT statements in a batch or a stored procedure which returns multiple result sets. Closing a result set tells the driver to move on to the next one and the only way to get to the next one is to fetch the stream of data until the next result set is encountered. There is no way to tell the server to skip ahead in the stream to the next result set. The server will not even begin producing/writing subsequent result sets to the stream until all previous rows are read.

[David-Engel]

This blog post has a good explanation of SQL Server's behavior:
https://blogs.msdn.microsoft.com/psssql/2008/07/23/how-it-works-attention-attention-or-should-i-say-cancel-the-query-and-be-sure-to-process-your-results/

How It Works: Attention, Attention or Should I say Cancel the Query and Be Sure to Process Your Results

I ran into this issue the other day and decided it would make a good post. Since I have seen this issue more times that I can count I will again attempt to provide details.

The attention event in SQL Server trace output indicates a query cancellation. There are three common ways this occurs.

1. Asynchronous cancellation (ODBC SQLCancel for example)
2. Query Timeout Exceeded and the client driver submits the attention
3. Results are not processed (very dangerous)

The attention is submitted to the SQL Server anytime the query is canceled and the client detects there are still pending results. If the results stream has been processed there is no need to tell SQL Server to cancel the query because SQL Server is already done with the query processing. So if you see the attention the results are not all processed.

An attention is treated by the SQL Server as an immediate processing termination. Stop right where you are and terminate the results.

Open Transaction
begin tran
update ...........
select (becomes blocked - attention arrives at the server)

At the time of the attention the transaction is not rolled back unless transaction abort (XACT_ABORT) has been enabled. The client needs to submit a rollback. If the client does not submit the rollback and continues other processing the transaction remains open and the behavior scope of the application becomes undefined.

Not Processing All Rows
I often see this by a pattern in a trace showing that the attention arrived right after the batch started. Generally milli-seconds afterwards and not something like a 30 second query timeout. This is often a clear indication that the client processed the first row or first few rows and discarded the rest of the result set unsafely. Take the following procedure for example.

create procedure spMyProc
as
begin
begin tran
insert into tbl2 select ... with output ....inserted....
commit tran
end

The procedure uses the OUTPUT clause of the insert to return the inserted rows to the client and let's say that the results from the output clause took more than a single network packet. The client library gets the first TDS packet and the first set of rows. If if client only processes the first result set the commit tran may never execute. Let's look at this in more detail with the actual ODBC client calls.
SQLExecute("spMyProc") <-------------- Returns as soon as the first result set if available (first set of rows in this case)
SQLFetch() <---------------- Retrieves the a row (should be done in a loop)
SQLFreeStmt() <------------ Releases the statement and if results are pending issues a SQLCancel.
So if the application only processes the first result it thinks the procedure ran successfully but because it did not process all results the SQLFreeStmt will issue the attention and cancel the procedure execution. Since we have not completed the insert (still streaming output rows) the commit tran is never executed (attention stops processing immediately). Data and application behavior becomes inconsistent. I have even seen customers increase the default packet size to allow the procedure to stream all rows in the first packet and complete until they get their application corrected.

The application should look like the following.
SQLExecute()
do
{
while(SQLFetch())
{
}
} while(SQLMoreResults())
SQLFreeStmt()

ODBC Trace
Here is an example of a bad application pattern as shown in an ODBC trace. Notice the SQLFetch is not called until it returns NO_MORE_ROWS and no call to SQLMoreResults is made. The SQLFreeStmt will submit the attention to the server and may create unexpected behavior for the application.

lord003 16 1000 fe4-13e0 EXIT SQLBindParameter with return code 0 (SQL_SUCCESS)
HSTMT 00B55530
UWORD 3
SWORD 1 <SQL_PARAM_INPUT>
SWORD 1 <SQL_C_CHAR>
SWORD 12 <SQL_VARCHAR>
SQLULEN 8
SWORD 0
PTR 0x00AFB2FF
SQLLEN 8
SQLLEN * 0x00000000
lord003 16 1000 fe4-13e0 EXIT SQLExecDirect with return code 0 (SQL_SUCCESS)
HSTMT 00B55530
UCHAR * 0x00B15DA8 [ -3] "SELECT * FROM xx00Online.dbo.loan (INDEX=rowno_loan) WHERE xx00Online.dbo.loan.rowno>? AND ((xx00Online.dbo.loan.balance < ?) AND (xx00Online.dbo.loan.paydue < ?)) ORDER BY xx00Online.dbo.loan.rowno 0"
SDWORD -3
lord003 16 1000 fe4-13e0 EXIT SQLFetch with return code 0 (SQL_SUCCESS)
HSTMT 00B55530
lord003 16 1000 fe4-13e0 ENTER SQLGetData
HSTMT 00B55530 <-------------------- STMT HANDLE
UWORD 1 <------------------- COLUMN NUMBER
SWORD -2 <SQL_C_BINARY>
PTR
SQLLEN 4
SQLLEN * 0x00B1B12C
lord003 16 1000 fe4-13e0 ENTER SQLFreeStmt
HSTMT 00B55530
UWORD 0 <SQL_CLOSE>
lord003 16 1000 fe4-13e0 EXIT SQLFreeStmt with return code 0 (SQL_SUCCESS)
HSTMT 00B55530
UWORD 0 <SQL_CLOSE>

Bob Dorr
SQL Server Senior Escalation Engineer

[David-Engel]

An enhancement would need to be made on the server side to facilitate different processing of result sets via TDS. Other alternatives are to use a driver which supports Multiple Active Result Sets (MARS), like ODBC, or server-side cursors.