FreeTDS Development Group

["Lowden, James K" <james.k.lowden AT alliancebernstein.com>]

I'm getting an invalid cursor state error trying to fetch data from a
stored procedure using prepare/execute from DBD::ODBC.  It looks like
DBD::ODBC thinks there is more than one result set and is trying to get
column descriptors when there are no metadata.  

Actually, there *are* two resultsets: the data, and the return status.
>From the log, it looks like we tell DBD there's a second resultset but
then refuse to provide it.  

This may be related to the db-lib error we found, wherein the
RETURNSTATUS was not available after dbresults returns NO_MORE_RESULTS.
I think we may be freeing the return status too soon.  

Details follow.  

--jkl

The perl (dies on the execute line):

    # call the stored procedure
    my $sth = $dbh->prepare( $procedure);
    $sth->execute;

The SQL:

alter procedure IsFreeTdsBroken
as begin

        select max(smDate) as LatestInputsmDate
        from DDMRaw
        return 0
end

The output (wrapped for your viewing pleasure):

$ perl  jkl simdb..IsFreeTdsBroken
DBD::ODBC::st fetchrow_array failed: 
        [unixODBC][FreeTDS][SQL Server]
                Invalid cursor state (SQL-24000)
                        (DBD: st_fetch/SQLFetch err=-1) 
        at jkl line 159.

Some of the log, annotated.  I set TDSDUMP=stderr and DBI_TRACE=3:

token.c:514:tds_process_tokens() state is COMPLETED
    SQLPrepare returned 0

    dbd_st_prepare'd sql f1084704768, ExecDirect=0
        simdb..IsFreeTdsBroken
    <- prepare= DBI::st=HASH(0x140a2ffe0) at jkl line 69
    -> execute for DBD::ODBC::st (DBI::st=HASH(0x140a2ffe0)~0x140a38550)
error.c:349:odbc_errs_reset
    dbd_st_execute (for hstmt 1084704768 before)...
error.c:349:odbc_errs_reset
odbc.c:2527:End prepare, execute
query.c:1573:tds_submit_execute()
util.c:119:Changing query state from IDLE to QUERYING
mem.c:519:tds_free_all_results()
util.c:119:Changing query state from QUERYING to PENDING
net.c:673:Sending packet
0000 03 01 00 29 00 00 01 00-0a 00 73 00 70 00 5f 00 |...).... ..s.p._.|
0010 65 00 78 00 65 00 63 00-75 00 74 00 65 00 00 00 |e.x.e.c. u.t.e...|
0020 00 00 26 04 04 01 00 00-00                      |..&..... .|

util.c:119:Changing query state from PENDING to READING
net.c:446:Received header
0000 04 01 00 63 00 5d 01 00-                        |...c.]..|

net.c:542:Received packet
0000 81 01 00 00 00 09 00 6f-04 11 4c 00 61 00 74 00 |.......o ..L.a.t.|
0010 65 00 73 00 74 00 49 00-6e 00 70 00 75 00 74 00 |e.s.t.I. n.p.u.t.|
0020 73 00 6d 00 44 00 61 00-74 00 65 00 d1 04 d3 97 |s.m.D.a. t.e.....|
0030 00 00 ff 11 00 c1 00 01-00 00 00 ff 11 00 c1 00 |........ ........|
0040 01 00 00 00 ff 01 00 e0-00 01 00 00 00 79 00 00 |........ .....y..|
0050 00 00 fe 00 00 e0 00 01-00 00 00                |........ ...|

token.c:526:processing result tokens.  marker is  81(TDS7_RESULT)
mem.c:519:tds_free_all_results()
token.c:1472:processing TDS7 result. set current_results to
tds->res_info
read.c:179:tds_get_string: reading 34 from wire to give 17 to client.
token.c:1414:tds7_get_data_info:
        colname = LatestInputsmDate (17 bytes)
        type = 111 (datetime-null)
        server's type = 111 (datetime-null)
        column_varint_size = 1
        column_size = 4 (4 on server)
util.c:119:Changing query state from READING to PENDING
util.c:119:Changing query state from PENDING to READING
token.c:526:processing result tokens.  marker is  d1(ROW)
util.c:119:Changing query state from READING to PENDING

[So far, so good.  The server executed the query and returned the 1-row,
1-column result, a datetime value.]

dbd_error: err_rc=0 rc=0 s/d/e: 1084704768/1084694528/1084712448
dbd_error: err_rc=0 rc=0 s/d/e: 0/1084694528/1084712448
dbd_error: err_rc=0 rc=0 s/d/e: 0/0/1084712448

[I don't know what these dbd_errors mean these mean.]

error.c:349:odbc_errs_reset
error.c:349:odbc_errs_reset
    dbd_describe sql 1084704768: num_fields=1

[DBD seems to know that there's one column]

error.c:349:odbc_errs_reset
error.c:349:odbc_errs_reset
odbc.c:1524:odbc:SQLColAttribute: fDescType is 6

[fDescType 6 is SQL_COLUMN_DISPLAY_SIZE]

error.c:349:odbc_errs_reset
odbc.c:1524:odbc:SQLColAttribute: fDescType is 3

[fDescType 3 is SQL_COLUMN_LENGTH]

      col  1: TIMESTAMP (93) len=  4 disp= 25, prec=  4 scale=0

[DBD seems to know it's a 4-byte column displayed in 25 characters]

error.c:349:odbc_errs_reset
error.c:349:odbc_errs_reset
      col  1: 'LatestInputsmDate' sqltype=TIMESTAMP, ctype=SQL_C_CHAR,
maxlen=25, (dp = 0, cp = 0)
dbd_describe failed, dbd_st_execute #2...!

[That doesn't look good.  What failed?  But we keep going....]

    <- execute= -1 at jkl line 70
    -> fetchrow_array for DBD::ODBC::st
(DBI::st=HASH(0x140a2ffe0)~0x140a38550)

[Now DBD will try to fetch the row, which seems to work....]

error.c:349:odbc_errs_reset
util.c:119:Changing query state from PENDING to READING
token.c:526:processing result tokens.  marker is  d1(ROW)
token.c:1863:tds_get_data: column 0, type 111, varint size 1
token.c:1920:processing row.  column size is 4
util.c:119:Changing query state from READING to PENDING
convert_tds2sql.c:62:convert_tds2sql: src is 58 dest = 1
convert_tds2sql.c:113:convert_tds2sql: outputting character data destlen
= 25
       SQLFetch rc 0
    dbih_setup_fbav for 1 fields => 0x140a2e700
fetch num_fields=1
    <- fetchrow_array= ( '2006-06-01 00:00:00' ) [1 items] row1 at jkl
line 157 via jkl line 73
    -> fetchrow_array for DBD::ODBC::st
(DBI::st=HASH(0x140a2ffe0)~0x140a38550)

[We returned 25 bytes of converted data to DBD.]

error.c:349:odbc_errs_reset
util.c:119:Changing query state from PENDING to READING
token.c:526:processing result tokens.  marker is  ff(DONEINPROC)
token.c:2143:tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
token.c:2175:                rows_affected = 1
util.c:119:Changing query state from READING to PENDING
util.c:119:Changing query state from PENDING to READING
token.c:526:processing result tokens.  marker is  ff(DONEINPROC)
token.c:2143:tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
token.c:2175:                rows_affected = 1
util.c:119:Changing query state from READING to PENDING
util.c:119:Changing query state from PENDING to READING
token.c:526:processing result tokens.  marker is  ff(DONEINPROC)
token.c:2143:tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
util.c:119:Changing query state from READING to PENDING
util.c:119:Changing query state from PENDING to READING
token.c:526:processing result tokens.  marker is  79(RETURNSTATUS)
token.c:526:processing result tokens.  marker is  fe(DONEPROC)
token.c:2143:tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 0

[Finally, we got the RETURNSTATUS token.  No more results.]

token.c:2159:tds_process_end() state set to TDS_IDLE
util.c:119:Changing query state from READING to IDLE
util.c:119:Changing query state from IDLE to PENDING
odbc.c:2891:SQLFetch: NO_DATA_FOUND
       SQLFetch rc 100
error.c:349:odbc_errs_reset
token.c:514:tds_process_tokens() state is COMPLETED
mem.c:519:tds_free_all_results()
MORE Results!

[DBD thinks there are more results?  It's expecting the RETURNSTATUS
value?  But FreeTDS has already freed all results.]

error.c:349:odbc_errs_reset
error.c:349:odbc_errs_reset
    dbd_describe sql 1084704768: num_fields=0
    dbd_describe skipped (no result cols) (sql f1084704768)
MORE Results dbd_describe success...!

[DBD discovers there's no resultset (0 columns). An odd kind of
"success"!]

    <- fetchrow_array= ( ) [0 items] row1 at jkl line 159 via jkl line
73
    -> FETCH for DBD::ODBC::st (DBI::st=HASH(0x140a38550)~INNER
'Active')
    .. FETCH DBI::st=HASH(0x140a38550) 'Active' = 1
    <- FETCH= 1 at jkl line 157 via jkl line 73
    -> fetchrow_array for DBD::ODBC::st
(DBI::st=HASH(0x140a2ffe0)~0x140a38550)

[Now DBD tries fetchrow_array again?  Maybe just to find out the
error....]

error.c:349:odbc_errs_reset
error.c:395:odbc_errs_add
error.c:332:odbc_get_v2state
error.c:316:odbc_get_msg
error.c:616:SQLGetDiagRec
error.c:520:_SQLGetDiagRec 1
error.c:251:rank_errors
error.c:564:_SQLGetDiagRec -> [FreeTDS][SQL Server]Invalid cursor state
error.c:616:SQLGetDiagRec
error.c:520:_SQLGetDiagRec 2

[FreeTDS returns 24000]

       SQLFetch rc -1
dbd_error: err_rc=-1 rc=0 s/d/e: 1084704768/1084694528/1084712448
dbd_error: SQL-24000 (native 0): [unixODBC][FreeTDS][SQL Server]Invalid
cursor state (SQL-24000)
dbd_error: err_rc=-1 rc=0 s/d/e: 0/1084694528/1084712448
dbd_error: err_rc=-1 rc=0 s/d/e: 0/0/1084712448
st_fetch/SQLFetch error -1 recorded: [unixODBC][FreeTDS][SQL
Server]Invalid cursor state (SQL-24000)(DBD: st_fetch/SQLFetch err=-1)
error.c:349:odbc_errs_reset
query.c:1709:tds_submit_unprepare() eidl6f9000
util.c:119:Changing query state from IDLE to QUERYING
mem.c:519:tds_free_all_results()



-----------------------------------------
The information contained in this transmission may be privileged and
confidential and is intended only for the use of the person(s) named
above. If you are not the intended recipient, or an employee or agent 
responsible
for delivering this message to the intended recipient, any review, 
dissemination,
distribution or duplication of this communication is strictly prohibited. If 
you are
not the intended recipient, please contact the sender immediately by reply 
e-mail
and destroy all copies of the original message. Please note that we do not 
accept
account orders and/or instructions by e-mail, and therefore will not be 
responsible
for carrying out such orders and/or instructions.  If you, as the intended 
recipient
of this message, the purpose of which is to inform and update our clients, 
prospects
and consultants of developments relating to our services and products, would 
not
like to receive further e-mail correspondence from the sender, please "reply" 
to the
sender indicating your wishes.  In the U.S.: 1345 Avenue of the Americas, New 
York,
NY 10105.