FreeTDS Development Group

[Krzysztof Chodak <krzysztof.chodak AT gmail.com>]

That is why I am still saying it.
[image: Inline image 1]
My first trace was on wire using wireshark and I saw repetitive info like
above.

On Thu, Apr 5, 2012 at 12:58, Frediano Ziglio <freddy77 AT gmail.com> wrote:

> Why you keep saying that server report malformed packets ??
> Server just drop connection without any notice to client so there is
> nothing wrong in capture.
>
> Frediano
>
> Il 05 aprile 2012 07:32, Krzysztof Chodak <krzysztof.chodak AT gmail.com>
> ha scritto:
> > Thanks you James for fruitful analysis.
> > (error message when posting zip was:
> > "Google tried to deliver your message, but it was rejected by the
> > recipient domain. We recommend contacting the other email provider for
> > further information about the cause of this error. The error that the
> > other server returned was: 550 550 5.7.1 illegal attachment type
> > (state 18)."
> > As it was 335K it was over the limit)
> > Thank you Ken for ticketing and Frediano for a fix.
> >
> > I would like to catch some more of your attention and get back to my
> > first post and probably the core source of the
> >  problem. Why server is dropping the connection? James - would you be
> > so kind to have a look at packets dump I initially posted (captured by
> > wireshark,
> https://docs.google.com/open?id=0B8Pbr6Jr1eaCa1R0NnVfdnpUb1M4a0pVVGl3WEZTZw
> )
> > and try to check why server is reporting malformed TDS packets? I
> > could also try to help but I would need to know where TDS 7.1 protocol
> > documentation resides?
> >
> > On Thu, Apr 5, 2012 at 08:18, Frediano Ziglio <freddy77 AT gmail.com>
> wrote:
> >> Il giorno 04/apr/2012, alle ore 22:18, "James K. Lowden" <
> jklowden AT freetds.org> ha scritto:
> >>
> >>> On Wed, 4 Apr 2012 13:00:05 +0200
> >>> Krzysztof Chodak <krzysztof.chodak AT gmail.com> 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
> >>
> _______________________________________________
> FreeTDS mailing list
> FreeTDS AT lists.ibiblio.org
> http://lists.ibiblio.org/mailman/listinfo/freetds
>

Attachment: 2012-03-22 20-22-52.png
Description: PNG image