Am 09-11-2015 22:21, schrieb Willy Tarreau:
On Mon, Nov 09, 2015 at 10:15:46PM +0100, Aleksandar Lazic wrote:
########
...
epoll_wait(3, {}, 200, 1000) = 0
epoll_wait(3, {{EPOLLIN, {u32=5, u64=5}}}, 200, 1000) = 1
accept4(5, {sa_family=AF_INET, sin_port=htons(52310),
sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_NONBLOCK) = 7
setsockopt(7, SOL_TCP, TCP_NODELAY, [1], 4) = 0
accept4(5, 0x7ffca18022c0, [128], SOCK_NONBLOCK) = -1 EAGAIN (Resource
temporarily unavailable)
recvfrom(7, "GET / HTTP/1.1\r\nUser-Agent: curl/7.22.0
(x86_64-pc-linux-gnu) libcurl/7.22.0 OpenSSL/1.0.1 zlib/1.2.3.4
libidn/1.23 librtmp/2.3\r\nHost: 127.0.0.1:7992\r\nAccept:
*/*\r\n\r\n",
16384, MSG_PEEK, NULL, NULL) = 166
close(7) = 0
epoll_wait(3, {}, 200, 1000) = 0
...
########
It was aborted very early, I think it even didn't become a session,
though I could be wrong. You need a session for a minimum of debugging
to work.
(...)
Other terminal.
########
curl -vk http://127.0.0.1:7992/
* About to connect() to 127.0.0.1 port 7992 (#0)
* Trying 127.0.0.1... connected
>GET / HTTP/1.1
>User-Agent: curl/7.22.0 (x86_64-pc-linux-gnu) libcurl/7.22.0
>OpenSSL/1.0.1 zlib/1.2.3.4 libidn/1.23 librtmp/2.3
>Host: 127.0.0.1:7992
>Accept: */*
>
* Recv failure: Connection reset by peer
* Closing connection #0
curl: (56) Recv failure: Connection reset by peer
########
Confirmed here.
Okay after removing accept-proxy from
bind *:${HTTP_BIND_PORT} accept-proxy tfo
It comes what expected.
Using epoll() as the polling mechanism.
00000000:http-in.accept(0005)=0007 from [127.0.0.1:53420]
[3995514114] process_stream:1662: task=0xa27410 s=0xa59600,
sfl=0x00000080, rq=0xa59610, rp=0xa59650, exp(r,w)=0,0 rqf=00908002
rpf=80000000 rqh=166 rqt=0 rph=0 rpt=0 cs=7 ss=0, cet=0x0 set=0x0 retr=0
[3995514114] tcp_inspect_request: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=00908002 bh=166 analysers=36
[3995514114] http_wait_for_request: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=00908002 bh=166 analysers=34
00000000:http-in.clireq[0007:ffffffff]: GET / HTTP/1.1
00000000:http-in.clihdr[0007:ffffffff]: User-Agent: curl/7.22.0
(x86_64-pc-linux-gnu) libcurl/7.22.0 OpenSSL/1.0.1 zlib/1.2.3.4
libidn/1.23 librtmp/2.3
00000000:http-in.clihdr[0007:ffffffff]: Host: 127.0.0.1:7992
00000000:http-in.clihdr[0007:ffffffff]: Accept: */*
[3995514114] http_process_req_common: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=00908002 bh=166 analysers=30
[3995514114] process_switching_rules: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=04908002 bh=166 analysers=00
[3995514114] http_process_req_common: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=04908002 bh=166 analysers=280
[3995514114] http_process_request: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=04908002 bh=166 analysers=200
[3995514114] sess_prepare_conn_req: sess=0xa59600 rq=0xa59610,
rp=0xa59650, exp(r,w)=0,0 rqf=04900002 rpf=80000000 rqh=0 rqt=194 rph=0
rpt=0 cs=7 ss=1
assign_server : s=0xa59600
[3995514114] sess_update_stream_int: sess=0xa59600 rq=0xa59610,
rp=0xa59650, exp(r,w)=0,0 rqf=04900002 rpf=80000000 rqh=0 rqt=194 rph=0
rpt=0 cs=7 ss=4
assign_server_address : s=0xa59600
[3995514114] queuing with exp=3995519114 req->rex=3995544114 req->wex=0
req->ana_exp=0 rep->rex=0 rep->wex=0, si[0].exp=0, si[1].exp=3995519114,
cs=7, ss=5
[3995514115] process_stream:1662: task=0xa27410 s=0xa59600,
sfl=0x000004ce, rq=0xa59610, rp=0xa59650, exp(r,w)=3995544114,0
rqf=00840300 rpf=80500000 rqh=0 rqt=0 rph=0 rpt=0 cs=7 ss=7, cet=0x0
set=0x0 retr=3
[3995514115] http_wait_for_response: stream=0xa59600 b=0xa59650,
exp(r,w)=0,0 bf=80508000 bh=0 analysers=60000
[3995514115] queuing with exp=3995544115 req->rex=0 req->wex=0
req->ana_exp=0 rep->rex=3995544115 rep->wex=0, si[0].exp=0, si[1].exp=0,
cs=7, ss=7
[3995514115] process_stream:1662: task=0xa27410 s=0xa59600,
sfl=0x000004ce, rq=0xa59610, rp=0xa59650, exp(r,w)=0,0 rqf=00840000
rpf=80000002 rqh=0 rqt=0 rph=3333 rpt=0 cs=7 ss=7, cet=0x0 set=0x0
retr=3
[3995514115] http_wait_for_response: stream=0xa59600 b=0xa59650,
exp(r,w)=0,0 bf=80008002 bh=3333 analysers=60000
00000000:<DEST>.srvrep[0007:0008]: HTTP/1.1 200 OK
00000000:<DEST>.srvhdr[0007:0008]: Server: nginx/1.9.6
00000000:<DEST>.srvhdr[0007:0008]: Date: Mon, 09 Nov 2015 21:28:45 GMT
00000000:<DEST>.srvhdr[0007:0008]: Content-Type: text/html
00000000:<DEST>.srvhdr[0007:0008]: Content-Length: 3095
00000000:<DEST>.srvhdr[0007:0008]: Last-Modified: Wed, 18 Jan 2012
10:17:45 GMT
00000000:<DEST>.srvhdr[0007:0008]: Connection: keep-alive
00000000:<DEST>.srvhdr[0007:0008]: ETag: "4f169c49-c17"
00000000:<DEST>.srvhdr[0007:0008]: Accept-Ranges: bytes
[3995514115] http_process_res_common: stream=0xa59600 b=0xa59650,
exp(r,w)=0,0 bf=80008002 bh=3309 analysers=40000
[3995514115] tcp_inspect_request: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=00c08000 bh=0 analysers=36
[3995514115] queuing with exp=3995519115 req->rex=3995544115 req->wex=0
req->ana_exp=3995519115 rep->rex=0 rep->wex=3995544115, si[0].exp=0,
si[1].exp=0, cs=7, ss=0
[3995514116] process_stream:1662: task=0xa27410 s=0xa59600,
sfl=0x00000080, rq=0xa59610, rp=0xa59650, exp(r,w)=0,0 rqf=00000021
rpf=80048200 rqh=0 rqt=0 rph=0 rpt=0 cs=7 ss=0, cet=0x0 set=0x0 retr=0
[3995514116] tcp_inspect_request: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=00808021 bh=0 analysers=36
[3995514116] http_wait_for_request: stream=0xa59600 b=0xa59610,
exp(r,w)=0,0 bf=00808021 bh=0 analysers=34
[3995514116] process_stream:1662: task=0xa27410 s=0xa59600,
sfl=0x00003080, rq=0xa59610, rp=0xa59650, exp(r,w)=0,0 rqf=0080e021
rpf=8004a260 rqh=0 rqt=0 rph=0 rpt=0 cs=8 ss=9, cet=0x0 set=0x0 retr=0
00000001:http-in.clicls[0007:0008]
00000001:http-in.closed[0007:0008]
########
Willy
