Re: tinytds based on freetds crashing

Il giorno 04/apr/2012, alle ore 22:18, "James K. Lowden" <[email protected]> ha scritto:

> On Wed, 4 Apr 2012 13:00:05 +0200
> Krzysztof Chodak <[email protected]> wrote:
> 
>>> Here it is: TDSDUMP log with a (ruby/tinytds/freetds) crash at the
>>> end
>> 
>> list does not like zip attachments so file is placed here:
>> https://docs.google.com/open?id=0B8Pbr6Jr1eaCZnFCUDk3LWxTYXVncFpCaUdfdjhIdw
> 
> (What message did you get posting a zip file?  It should be
> permitted provided it's under 75 KB.)  
> 
> The TDSDUMP log clarifies several points.  
> 
>    FreeTDS 0.91
>    TDS 7.1 
>    Windows (log file is on C: drive)
>    client charset is UTF-8 (unusual but OK)
> 
> The trouble starts when the server disconnects unexpectedly.  It ends
> when unbounded recursion caused by the application's error handler
> consumes the stack and crashes the process.  
> 
> Why the server disconnected isn't clear or even certain.  All that we
> know is that the last write returned "Connection reset by peer", which
> normally indicates the connection was closed by the remote.  
> 
> The last packet sent is on line 81590 of the log file
> 
>    SELECT TOP (1) [users].* FROM [users] 
>    WHERE [users].[login] = N''bradoscb''
> 
> Immediately beneath the dumped packet we see
> 
> net.c:667:send(2) failed: 10054 
>        (WSAECONNRESET: Connection reset by peer.) 
> 
> which tells us the library detected the OS error.  Then 
> 
> util.c:331:tdserror(03a04588, 03fe49b0, 20006, 10054)
> dblib.c:7929:dbperror(03d32008, 20006, 10054)
> dblib.c:7981:20006: "Write to the server failed"
> 
> per normal, then 
> 
> dblib.c:5780:dbgetuserdata(03d32008)
> dblib.c:5780:dbgetuserdata(03d32008)
> dblib.c:4880:dbdead(03d32008) [alive]
> 
> wrong.  A disconnected session is anything but alive. 
> 
> dblib.c:4639:dbsqlok(03d32008)
> dblib.c:4669:dbsqlok() not done, calling tds_process_tokens()
> 
> db-lib still thinks the session is up ...
> 
> token.c:540:tds_process_tokens(03fe49b0, 00226220, 0022621c, 0x6914)
> util.c:156:Changed query state from PENDING to READING
> util.c:331:tdserror(03a04588, 03fe49b0, 20004, 10054)
> dblib.c:7929:dbperror(03d32008, 20004, 10054)
> dblib.c:7981:20004: "Read from the server failed"
> 
> but the read failed ... 
> 
> dblib.c:5780:dbgetuserdata(03d32008)
> dblib.c:5780:dbgetuserdata(03d32008)
> dblib.c:4880:dbdead(03d32008) [alive]
> dblib.c:4639:dbsqlok(03d32008)
> dblib.c:4669:dbsqlok() not done, calling tds_process_tokens()
> 
> and we enter an infinite loop.  
> 
> Analysis
> ---------
> 
> Windows returns a valid error code WSAECONNRESET.  This is reported to
> the log in tds/net.c:tds_goodwrite() on line 667.  That logic closes
> the socket and returns -1 to tds_write_packet().
> 
> How did we get there?  The log shows
> 
> dblib.c:6862:dbsqlsend(03d32008)
> write.c:168:tds_put_string wrote 194 bytes
> 
> tds_put_string() calls 
> tds_put_n() calls 
> tds_write_packet
> 
> tds_write_packet() returrns TDS_FAIL to tds_put_n()
> 
> which discards the return code.  :-(
> 
> Propogating the error code is not the only way error information is
> provided to db-lib from libtds.  tds_goodwrite()  also calls tdserror
> (), which calls the client's error handler.  We see that in the log, too
> 
> util.c:331:tdserror(03a04588, 03fe49b0, 20006, 10054)
> dblib.c:7929:dbperror(03d32008, 20006, 10054)
> dblib.c:7981:20006: "Write to the server failed"
> 
> What we do *not* see in the log is the product of the next line in
> tdserror()
> 
>  tdsdump_log(TDS_DBG_FUNC, 
>    "tdserror: client library returned %s(%d)\n", retname(rc), rc);
> 
> The missing message in the log indicates the error handler is Charlie on
> the MTA: it Never Returned.  
> 
> It would appear -- whether by design or not -- that the
> client-installed error handler makes db-lib calls, in particular
> dbsqlok().  Don't do that.  It engenders infinite recursion just
> as evinced by the log:
> 
> dblib.c:4669:dbsqlok() not done, calling tds_process_tokens()
> token.c:540:tds_process_tokens(03fe49b0, 00226220, 0022621c, 0x6914)
> util.c:331:tdserror(03a04588, 03fe49b0, 20004, 10054)
> dblib.c:7929:dbperror(03d32008, 20004, 10054)
> dblib.c:7981:20004: "Read from the server failed"
> # no tdserror message here 
> # to indicate the handler's return code
> ...
> dblib.c:4639:dbsqlok(03d32008) # from within handler
> dblib.c:4669:dbsqlok() not done, calling tds_process_tokens()
> 
> (It looks like an infinite loop, but it's infinite recursion.
> Computationally equivalent constructs, just one is more familar to C
> programmers than the other.)  
> 
> Incidentally, this would also explain why dbdead() reports "[active]".
> In tds_goodread(), the socket isn't closed until after tdserror()
> returns.  Because the socket is still open within the recursion, all
> calls to dbdead() continue to find the socket open and it reports
> "active".  
> 

Fixed in both 0.91 and master!

> Give your error handler a nickle and let it return.  Otherwise it will
> eventually devour the stack along with your process.  
> 
> --jkl
> 

Frediano