Re: SQLGetTypeInfo() fails when it is called for the second time

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