On Thu, Oct 25, 2001 at 03:16:46PM +0100, Joe Orton wrote:
> On Thu, Oct 25, 2001 at 03:58:10PM +0200, Daniel Stenberg wrote:
> > To see an entire neon dump for a failure, get this:
> > http://storebror.haxx.se/~daniel/svn/neon-dump.bz2 (373KB) or get the last
> > 200 lines of that logfile here:
> > http://storebror.haxx.se/~daniel/svn/neon-dump-200
> Thanks! Well; this shows that it is a persistent connection handling
> problem, at least. I'd thought that persistent connections were still
> turned off, looks like this they aren't for the second session. Putting
> ne_sess_persist(sess2, 0);
> after the other ne_set_persist call in session.c should work around
Joe... did you look at that ethereal dump? As far as I can tell, this is a
*client* problem. It has nothing to do with server persistence, or problems
on the server. I fixed the server persistence problems a while ago.
My initial investigation last night was flawed. I saw something that was
weird, but that was just fallout from earlier in the trace.
The root of the problem is some kind of packet loss. At t=1.73, the client
sent a SYN to the server. This packet was lost, the server did not respond,
so at t=4.72, the client sent it again. This time, the server responded at
t=4.87. The client ACK'd the response, but that got lost and the server
resent the SYN response at t=4.90.
Next up, the client sends a request at t=4.879. The server does not respond
to this, so the client resends at t=24.38. It sends again at t=63.4.
Now... those requests are occurring over a different session than the one
used for GET (a bug, but not the cause here).
*While* that resend is occuring, the Apache server times out the GET session
at t=16.68 (15 seconds after the prior activity on that session). This is
*normal* behavior, and is to be expected.
Here is where things get interesting. The server closes the connection at
t=16.68. The client ACKs that at t=16.72 (I'm not sure whether the server
gets that packet or not, but I think it is irrelevant). Next, the client
tries to send a GET request at t=84.83. I believe this generates an error on
the client, so Neon closes its side of the connection at t=84.83 (the FIN,
ACK packet). However, the bug is this: Neon *resends* the request on the
same socket that it just tried to shut down. This ocurs at t=85.29. The
server gets that packet, know the TCP connection is closed, so it sends an
RST packet at t=85.47.
It is that RST packet that causes Neon to throw up the "server closed
connection" error message.
At this point, I would recommendation re-enabling persistent connections and
debugging the Neon problem.
And to those with packet loss occurring: you can see the delays during
checkout were caused by that loss rather than client/server problems. The
final error is definitely a client problem, though :-)
Greg Stein, http://www.lyra.org/
To unsubscribe, e-mail: email@example.com
For additional commands, e-mail: firstname.lastname@example.org
Received on Sat Oct 21 14:36:46 2006