On Fri, 11 Jan 2013, Yang Tse wrote:
I'll study your trace, compare with mine and later on start to debug this.
Just wanted now to handle you all logs for test 64.
Can you first check and see if there's a time descripancy between the trace64
log and the http_server.log ? I can't make sense of the times in there:
http server:
00:25:55.470998 ====> Client connect
00:25:55.470998 TCP_NODELAY set
00:25:55.470998 accept_connection 3 returned 4
00:25:55.470998 accept_connection 3 returned 0
00:25:55.490998 Read 84 bytes
00:25:55.490998 Process 84 bytes request
00:25:55.490998 Got request: GET /64 HTTP/1.1
trace:
00:25:55.461476 == Info: About to connect() to 127.0.0.1 port 8990 (#0)
00:25:55.471476 == Info: Trying 127.0.0.1...
00:25:55.491476 == Info: connected
00:25:55.491476 == Info: Connected to 127.0.0.1 (127.0.0.1) port 8990 (#0)
00:25:55.491476 == Info: 0xb4f1a0 is at send pipe head!
00:25:55.491476 == Info: STATE: CONNECT => DO handle 0xb72f68; line 1025
(connection #0)
00:25:55.491476 == Info: Server auth using Digest with user 'testuser'
00:25:55.491476 => Send header, 84 bytes (0x54)
See? The server claims it got the GET already before libcurl logged
'connected' !
And then for the next sequence of interest to me:
server log:
00:25:55.510998 Response sent (245 bytes) and written to log/server.response
00:25:55.510998 instructed to close connection after server-reply
00:25:55.510998 ====> Client disconnect 0
trace log:
00:25:55.511476 == Info: Connection #0 to host 127.0.0.1 left intact
00:25:55.511476 == Info: Issue another request to this URL:
'http://127.0.0.1:8990/64'
00:25:55.511476 == Info: Found bundle for host 127.0.0.1: 0xb7c180
00:25:55.511476 == Info: Re-using existing connection! (#0) with host
127.0.0.1
00:25:55.511476 == Info: Connected to 127.0.0.1 (127.0.0.1) port 8990 (#0)
... which looks like SocketIsDead() didn't think the connection it tries to
re-use is dead, but the time stamps indicate it should've seen it.
Then there's clearly a bug when things went south due to the dead connection
being attempted for sending the request on:
00:25:55.571476 == Info: Recv failure: Connection reset by peer
00:25:55.571476 == Info: Connection died, retrying a fresh connect
00:25:55.571476 == Info: Recv failure: Connection reset by peer
00:25:55.571476 == Info: Connection died, retrying a fresh connect
... it doesn't look like this is truly trying a fresh connect, it seems to
mostly just _say_ it!
--
/ daniel.haxx.se
-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html
