Skip to Content.
Sympa Menu

freetds - Re: [freetds] SQLGetTypeInfo() fails when it is called for the second time

freetds AT lists.ibiblio.org

Subject: FreeTDS Development Group

List archive

Chronological Thread  
  • From: "James K. Lowden" <jklowden AT freetds.org>
  • To: Marko Polloto <marko68 AT gmx.net>, FreeTDS Development Group <freetds AT lists.ibiblio.org>
  • Subject: Re: [freetds] SQLGetTypeInfo() fails when it is called for the second time
  • Date: Thu, 9 Oct 2008 00:13:52 -0400

marko68 GMX wrote:
> JKL> marko68 GMX wrote:
> >> The main idea behind this cycle is an attempt to figure out the
> >right > correspondence between available (supported by the
> >application) data > types and the ones supported by MS SQL. The first
> >call of the > function returns the requested type info, but the second
> >call > fails: SQLGetTypeInfo returns -1. The call of SQLGetDiagRec
> >> returns the following error:
> >>
> >> 08S01 - [FreeTDS][SQL Server]Communication link failure
>
> JKL> Please post a TDSDUMP log of the session. Perhaps that will shed
> JKL> some light.
>
> The log file is attached (43Kb). And although I have found the
> workaroud (every time when I sequentially call the function
> find_an_appropriate_data_type() I allocate new handle) I would be
> interested to know your opinion on what happens in this case.

It appears that FreeTDS is violating the TDS protocol.

Every call to SQLGetTypeInfo() initiates a query to the server:

EXEC sp_datatype_info ...

The problem is that the packet header of each query has the "last packet"
flag set ON e.g.:

15:42:07.350941 3197 (net.c:779):Sending packet
0000 01 01 00 3c 00 00 01 00-20 00 45 00 58 00 45 00 |...<.... .E.X.E.|
^^ last packet flag == 1

Rules of the game are that after the client sends the last packet (so
marked) of the query, it must read the results from the server until a
DONE packet arrives. Instead, your log shows 47 consecutive "last" writes
with no intervening reads:

$ grep packet$ logs/18707/freetds.log | awk '{print $3, $4}' | uniq -c
1 (login.c:735):quietly sending
1 (net.c:671):Received packet
1 (net.c:779):Sending packet
1 (net.c:671):Received packet
47 (net.c:779):Sending packet

Eventually the server gives up and disconnects. I'm surprised it's so
patient.

What's odd is that afaict you issued only *one* call to SQLGetTypeInfo:

$ awk -F'[:(]' '/:SQL/ {print $6}' logs/18707/freetds.log | uniq -c
3 SQLGetInfo
1 SQLAllocHandle
4 SQLGetStmtAttr
11 SQLGetInfo
1 SQLSetStmtAttr
2 SQLGetInfo
8 SQLBindCol
1 SQLGetTypeInfo
2 SQLGetDiagRec
2 SQLFreeStmt

Correct use of SQLGetTypeInfo is to fetch the results produced after each
call to it. If you do that, it should work fine. Trouble is, it seems
you *did* do that, but the driver wound up issuing the same query 47
times. Based on the log, it appears the bug is somewhere in _SQLExecute
or functions it calls:

$ awk -F'[:(]' '/:_*SQL/ {print $6}' logs/18707/freetds.log | uniq -c |
sed -ne '/Bind/,$p'
8 SQLBindCol
1 SQLGetTypeInfo
2 _SQLExecute
1 SQLGetDiagRec
1 _SQLGetDiagRec
1 SQLGetDiagRec
1 _SQLGetDiagRec
1 SQLFreeStmt
1 _SQLFreeStmt
1 SQLFreeStmt
1 _SQLFreeStmt

$ grep _SQLExecute logs/18707/freetds.log
15:42:07.344114 3197 (odbc.c:2965):_SQLExecute(0x208fe0)
15:42:07.344130 3197 (odbc.c:2970):_SQLExecute() starting with state 0

_SQLExecute never produces a log message indicating it's fetching results
("_SQLExecute: odbc_process_tokens returned result_type...."). Because it
contains no loop, the likely culprits are the tds_submit* functions.

That's all I've got.

HTH.

--jkl




Archive powered by MHonArc 2.6.24.

Top of Page