FreeTDS / freetds

Official FreeTDS repository
http://www.freetds.org/
GNU General Public License v2.0
463 stars 161 forks source link

Executing a direct query with declare clause in it fails to read the response #376

Open gbromov opened 3 years ago

gbromov commented 3 years ago

A query like this:

declare @x int
set @x = 100
select c = @x

works fine when using Microsoft ODBC driver, but for some reason FreeTDS can't read the results. I can't really understand what the logs say, but there is a weird entry: util.c:83:logic error: cannot change query state from IDLE to PENDING

Here's the relevant part of the log, maybe it'll be helpful:

odbc.c:1530:SQLAllocHandle(3, 053C1FD0, 0133F914)
odbc.c:1705:_SQLAllocStmt(053C1FD0, 0133F914)
odbc_export.h:801:SQLExecDirectW(053C75A8, 
declare @x int
set @x = 100
select c = @x
, 43)
prepare_query.c:208:parsing 0 parameters
odbc.c:3274:_SQLExecute(053C75A8)
odbc.c:3291:_SQLExecute() starting with state 0
mem.c:656:tds_free_all_results()
util.c:179:Changed query state from IDLE to WRITING
packet.c:852:Sending packet
0000 01 01 00 74 00 00 01 00-16 00 00 00 12 00 00 00 |...t.... ........|
0010 02 00 00 00 00 00 00 00-00 00 01 00 00 00 0a 00 |........ ........|
0020 64 00 65 00 63 00 6c 00-61 00 72 00 65 00 20 00 |d.e.c.l. a.r.e. .|
0030 40 00 78 00 20 00 69 00-6e 00 74 00 0a 00 73 00 |@.x. .i. n.t...s.|
0040 65 00 74 00 20 00 40 00-78 00 20 00 3d 00 20 00 |e.t. .@. x. .=. .|
0050 31 00 30 00 30 00 0a 00-73 00 65 00 6c 00 65 00 |1.0.0... s.e.l.e.|
0060 63 00 74 00 20 00 63 00-20 00 3d 00 20 00 40 00 |c.t. .c.  .=. .@.|
0070 78 00 0a 00            -                        |x...|

util.c:179:Changed query state from WRITING to PENDING
token.c:554:tds_process_tokens(0541B9B8, 0133F768, 0133F75C, 0x6914)
util.c:179:Changed query state from PENDING to READING
packet.c:410:Received packet
0000 04 01 00 36 00 34 01 00-fd 11 00 c1 00 01 00 00 |...6.4.. ........|
0010 00 00 00 00 00 81 01 00-00 00 00 00 21 00 26 04 |........ ....!.&.|
0020 01 63 00 d1 04 64 00 00-00 fd 10 00 c1 00 01 00 |.c...d.. ........|
0030 00 00 00 00 00 00      -                        |......|

token.c:569:processing result tokens.  marker is  fd(DONE)
token.c:2096:tds_process_end: more_results = 1
        was_cancelled = 0
        error = 0
        done_count_valid = 1
token.c:2115:                rows_affected = 1
util.c:179:Changed query state from READING to PENDING
odbc.c:3615:odbc_process_tokens: tds_process_tokens returned 0
odbc.c:3616:    result_type=4052, TDS_DONE_COUNT=10, TDS_DONE_ERROR=0
odbc.c:3658:odbc_process_tokens: row_count=1
odbc.c:3437:_SQLExecute: odbc_process_tokens returned result_type 4052
odbc.c:4529:SQLNumResultCols(053C75A8, 0133F794)
odbc.c:4247:SQLFreeStmt(053C75A8, 0)
odbc.c:4164:_SQLFreeStmt(053C75A8, 0, 0)
query.c:2031:tds_send_cancel: not in_cancel and not idle
query.c:2078:tds_send_cancel: sending cancel packet
packet.c:852:Sending packet
0000 06 01 00 08 00 00 01 00-                        |........|

token.c:554:tds_process_tokens(0541B9B8, 0133F730, 00000000, 0x0)
util.c:179:Changed query state from PENDING to READING
token.c:569:processing result tokens.  marker is  81(TDS7_RESULT)
token.c:1574:processing TDS7 result metadata.
mem.c:656:tds_free_all_results()
token.c:1599:set current_results (1 column) to tds->res_info
token.c:1606:setting up 1 columns
token.c:1543:tds7_get_data_info: 
    colname = c
    type = 38 (integer-null)
    server's type = 38 (integer-null)
    column_varint_size = 1
    column_size = 4 (4 on server)
token.c:1615: name                 size/wsize      type/wtype      utype  
token.c:1616: -------------------- --------------- --------------- -------
token.c:1621: c                          4/4            38/38            0
token.c:569:processing result tokens.  marker is  d1(ROW)
token.c:1951:tds_process_row(): reading column 0 
data.c:716:tds_get_data: type 38, varint size 1
data.c:760:tds_get_data(): wire column size is 4 
token.c:569:processing result tokens.  marker is  fd(DONE)
token.c:2096:tds_process_end: more_results = 0
        was_cancelled = 0
        error = 0
        done_count_valid = 1
token.c:2115:                rows_affected = 1
packet.c:410:Received packet
0000 04 01 00 15 00 34 01 00-fd 20 00 fd 00 00 00 00 |.....4.. . ......|
0010 00 00 00 00 00         -                        |.....|

token.c:569:processing result tokens.  marker is  fd(DONE)
token.c:2096:tds_process_end: more_results = 0
        was_cancelled = 1
        error = 0
        done_count_valid = 0
token.c:2115:                rows_affected = 0
token.c:2118:tds_process_end() state set to TDS_IDLE
util.c:179:Changed query state from READING to IDLE
util.c:83:logic error: cannot change query state from IDLE to PENDING
util.c:179:Changed query state from IDLE to IDLE
odbc.c:4064:SQLFreeHandle(3, 053C75A8)
odbc.c:4164:_SQLFreeStmt(053C75A8, 1, 0)
fziglio commented 3 years ago

From the logs it seems that instead of reading the results you issue a cancel

gbromov commented 3 years ago

That's weird, I don't even know how to do that. These are the lines my code executes:

SQLHSTMT hStatement = nullptr;
SQLRETURN status_1 = SQLAllocHandle( SQL_HANDLE_STMT , hConnection , &hStatement );

std::u16string u16_sql = u"declare ..";
SQLRETURN status_2 = SQLExecDirect( hStatement , (SQLWCHAR*)&u16_sql[ 0 ] , (SQLINTEGER)u16_sql.size( ) );

SQLSMALLINT num_columns = -1;
SQLRETURN status_3 = SQLNumResultCols( hStatement , &num_columns );

status_1, status_2 and status_3 are all SQL_SUCCESS, and num_columns is set to 0.

gbromov commented 3 years ago

Actually maybe the problem is that since SQLNumResultCols returns zero columns, I am just calling SQLFreeStmt( ), SQLFreeHandle( ) instead of SQLFetch( ) first, that's why I am issuing the cancel? With driver reporting zero columns, I don't see a point in trying to SQLFetch( ), I am assuming that zero columns means no result set.

Even if I try calling SQLFetch( ), what can I do with it if there are no columns to read from.

fziglio commented 3 years ago

You are forgetting SQLMoreResults. But I won't expect an empty recordset looking at your query. It's pretty odd. The set statement should not produce that. Less the declare statement.

OT: personally I would prefer u16_sql.c_str() or u16_sql.data() instead of &u16_sql[0]

gbromov commented 3 years ago

Alright, weirdly enough calling SQLMoreResults worked. Apparently the second result set it what the select clause produces, what is the first one is unclear. I still believe this is a bug though, it feels like freetds somehow decided there should be two result sets from the statement, which shouldn't happen I think. Of course, it is possible that the response from the sql server is incorrect, but I don't have any knowledge of the protocol to verify it. Microsoft's ODBC driver works as expected here though - only one result set with one column and one row.

On the OT: How do you use those, c_str( ) returns const char16_t* while the function expects non-const pointer, and data( ) is a non-const function and the strings almost always (at least on my code) are passed by const reference. Do you const_cast those?