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: marko68 GMX <marko68 AT gmx.net>
  • To: "James K. Lowden" <jklowden AT freetds.org>
  • Cc: FreeTDS Development Group <freetds AT lists.ibiblio.org>
  • Subject: Re: [freetds] SQLGetTypeInfo() fails when it is called for the second time
  • Date: Wed, 8 Oct 2008 21:48:45 -0700

Hello James,

Thank you very much for the extensive analysis of the log file, I sent
you. Since I have already found the temporary workaround, which I
mentioned in my previous post, I will use it for the time being and
consider the problem solved.

Thanks,
Marko


JKL> It appears that FreeTDS is violating the TDS protocol.

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

JKL> EXEC sp_datatype_info ...

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

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

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

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

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

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

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

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

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

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

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

JKL> That's all I've got.

JKL> HTH.





Archive powered by MHonArc 2.6.24.

Top of Page