[freetds] SQLGetTypeInfo() fails when it is called for the second time
marko68 GMX
marko68 at gmx.net
Thu Oct 9 00:48:45 EDT 2008
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.
More information about the FreeTDS
mailing list