Skip to Content.
Sympa Menu

freetds - Re: [freetds] TDS Version problem

freetds AT lists.ibiblio.org

Subject: FreeTDS Development Group

List archive

Chronological Thread  
  • From: Frediano Ziglio <freddy77 AT gmail.com>
  • To: FreeTDS Development Group <freetds AT lists.ibiblio.org>
  • Subject: Re: [freetds] TDS Version problem
  • Date: Thu, 28 Feb 2008 22:10:42 +0100


Il giorno gio, 28/02/2008 alle 13.18 -0500, James K. Lowden ha scritto:
> Robin Smith wrote:
> > > It might be time for more detailed information. A TDSDUMP log will
> > > show what calls are being made to the ODBC driver and what happens
> > > next. Maybe in conjunction with the ODBC trace that will reveal
> > > something.
> >
> > Here are the logs.
>
> There are a few differences, and IMO a minor error in odbc.c. It looks
> like the problem stems either from differences in the query or in the TDS
> version. There's a mysterious error toward the end of the PHP log.
>
> I generated a diff on your logs, stripped of timestamps and memory
> addresses:
>
> $ for F in php isql; do perl -pe 's/^\d\d:\d\d:\d\d\.\d+ \d{4}//g;
> s/0x[[:xdigit:]]{6,8}/{addr}/g;' freetds.$F.log > $F; done; diff -u php
> isql | less -S
>
> That lets us look at the real differences. The first one is here:
>
> --- php 2008-02-28 11:39:20.000000000 -0500
> +++ isql 2008-02-28 11:39:20.000000000 -0500
> ...
> @@ -7,14 +7,14 @@
> (iconv.c:363):iconv to convert client-side data to the "ISO-8859-1"
> character
> (iconv.c:516):tds_iconv_info_init: converting "ISO-8859-1"->"UCS-2LE"
> (iconv.c:516):tds_iconv_info_init: converting "ISO-8859-1"->"UCS-2LE"
> - (net.c:192):Connecting to 172.16.3.146 port 1433 (TDS version 8.0)
> + (net.c:192):Connecting to 172.16.3.146 port 1433 (TDS version 7.0)
>
> With PHP you're running TDS 8.0. Does the problem go away if you set it
> to 7.0?
>
> That (I believe) leads to differences later e.g.:
>
> - (odbc.c:5533):SQLGetInfo({addr}, 8, {addr}, 4, (nil))
> - (odbc.c:4786):_SQLGetInfo({addr}, 8, {addr}, 4, (nil)
> - (odbc.c:6157):SQLSetStmtOption({addr}, 6, 2)
> - (odbc.c:5875):_SQLSetStmtAttr({addr}, 6, 0x2, -3)
> - (odbc.c:3192):SQLExecDirect({addr}, {addr}, -3)
> - (odbc.c:2949):_SQLExecute({addr})
> - (odbc.c:2954):_SQLExecute() starting with state 0
> - (query.c:2053):tds_cursor_declare() cursor id = 0
> - (query.c:2103):tds_cursor_open() cursor id = 0
> + (odbc.c:4087):SQLPrepare({addr}, select * from pro , -3)
> + (odbc.c:4151):Creating prepared statement
> (mem.c:563):tds_free_all_results()
> (util.c:162):Changed query state from IDLE to QUERYING
> - (query.c:2231):tds_cursor_open (): RPC call set up
> - (query.c:2235):tds_cursor_open (): cursor open completed
> + (util.c:162):Changed query state from QUERYING to PENDING
> (net.c:739):Sending packet
> -0000 03 01 00 60 00 00 01 00-ff ff 02 00 00 00 00 01 |...`.... ........|
> -0010 26 04 00 00 00 63 22 00-00 00 09 04 d0 00 34 22 |&....c". ......4"|
> -0020 00 00 00 53 00 45 00 4c-00 45 00 43 00 54 00 20 |...S.E.L .E.C.T. |
> -0030 00 2a 00 20 00 46 00 52-00 4f 00 4d 00 20 00 50 |.*. .F.R .O.M. .P|
> -0040 00 52 00 4f 00 00 01 26-04 04 02 00 00 00 00 01 |.R.O...& ........|
> -0050 26 04 04 01 20 00 00 00-01 26 04 04 00 00 00 00 |&... ... .&......|
> +0000 03 01 00 68 00 00 01 00-0a 00 73 00 70 00 5f 00 |...h.... ..s.p._.|
> +0010 70 00 72 00 65 00 70 00-61 00 72 00 65 00 00 00 |p.r.e.p. a.r.e...|
> +0020 00 01 26 04 00 00 00 63-00 00 00 00 ff ff ff ff |..&....c ........|
> +0030 00 00 63 24 00 00 00 24-00 00 00 73 00 65 00 6c |..c$...$ ...s.e.l|
> +0040 00 65 00 63 00 74 00 20-00 2a 00 20 00 66 00 72 |.e.c.t. .*. .f.r|
> +0050 00 6f 00 6d 00 20 00 70-00 72 00 6f 00 20 00 00 |.o.m. .p .r.o. ..|
> +0060 00 26 04 04 01 00 00 00- |.&......|
>
> where PHP executes SELECT while isql executes a prepared statement.
>
> Things diverge pretty far after that.
>
> I was fooled by these "errors" from the server:
>
> (odbc.c:2022):msgno 5703 20003
>
> Freddy, this is a mistake in odbc.c. It's not a 20003 TDSETIME error, as
> line 2022 says:
>
> tdsdump_log(TDS_DBG_INFO1, "msgno %d %d\n", (int) msg->msgno,
> TDSETIME);
>
> It's just "Changed language setting to [foo].".
>
> But PHP shows shows a real error, after which it stops sending anything:
>
> - (odbc.c:2022):msgno 16902 20003
>
> Message 16902 is "%hs: The value of parameter %hs is invalid."
>
> I don't know what that means. I did find this, but you said you're running
> 2000, not 7:
>
> http://support.microsoft.com/kb/252865
>
> Conclusions:
>
> 1. It might be something in the way TDS 8.0 is handled.
>
> 2. Your application should report errors such as 16902. Not sure why that
> didn't turn up before.
>
> 3. odbc.c shouldn't log all errors as timeout messages.
>
> I think you discovered a bug. Sorry I couldn't spot the actual real
> problem. Hope I got you and Frediano a little closer to its resolution.
> Thanks for the detailed problem report and for posting the logs.
>
> Regards,
>

Looking at

10:08:32.852823 2698 (net.c:739):Sending packet
0000 03 01 00 2e 00 00 01 00-ff ff 07 00 02 00 00 00 |........ ........|
0010 26 04 04 f0 de bc 0a 00-00 26 04 04 02 00 00 00 |&....... .&......|
0020 00 00 26 04 00 00 00 26-04 04 00 00 00 00 |..&....& ......|

10:08:32.852884 2698 (token.c:495):tds_process_tokens(0x8021b7e8, 0xbfc644c4,
0xbfc644c0, 0x6d00)
10:08:32.852900 2698 (util.c:162):Changed query state from PENDING to READING
10:08:32.853500 2698 (net.c:547):Received header
0000 04 01 00 a1 00 45 01 00- |.....E..|

10:08:32.853525 2698 (net.c:626):Received packet
0000 aa 88 00 06 42 00 00 07-10 3a 00 73 00 70 00 5f |....B... .:.s.p._|
0010 00 63 00 75 00 72 00 73-00 6f 00 72 00 66 00 65 |.c.u.r.s .o.r.f.e|
0020 00 74 00 63 00 68 00 3a-00 20 00 54 00 68 00 65 |.t.c.h.: . .T.h.e|
0030 00 20 00 76 00 61 00 6c-00 75 00 65 00 20 00 6f |. .v.a.l .u.e. .o|
0040 00 66 00 20 00 70 00 61-00 72 00 61 00 6d 00 65 |.f. .p.a .r.a.m.e|
0050 00 74 00 65 00 72 00 20-00 27 00 6e 00 72 00 6f |.t.e.r. .'.n.r.o|
0060 00 77 00 73 00 27 00 20-00 69 00 73 00 20 00 69 |.w.s.'. .i.s. .i|
0070 00 6e 00 76 00 61 00 6c-00 69 00 64 00 2e 00 04 |.n.v.a.l .i.d....|
0080 45 00 52 00 50 00 37 00-00 01 00 79 01 00 00 00 |E.R.P.7. ...y....|
0090 fe 10 00 e0 00 00 00 00-00 |........ .|

sp_cursorfetch don't like 0 as nrows... I agree.

sp_cursorfetch is issued in _SQLFetch called by SQLExtendedFetch which
override (corretcly) row numbers (stmt->ard->header.sql_desc_array_size
in SQLFetch) with stmt->sql_rowset_size. The problem is that
stmt->sql_rowset_size is initialized as SQL_BIND_BY_COLUMN while should
be initialized with 1... I think also that stmt->sql_rowset_size cannot
be <1.

I think that replacing

/* is not the same of using APD sql_desc_bind_type */
stmt->sql_rowset_size = SQL_BIND_BY_COLUMN;

with

stmt->sql_rowset_size = 1;

should fix the problem (I know, comment remove is not necessary... but
it's wrong :) )

Here is too late to test this issue... good night!

freddy77






Archive powered by MHonArc 2.6.24.

Top of Page