On Tue, May 27, 2014 at 08:20:07PM +0200, Jakov Sosic wrote:
> On 05/27/2014 08:04 PM, Sasha Pachev wrote:
> >Jakov:
> >
> >There could be multiple reasons. My first thought is to run a network
> >sniffer like tcpdump, capture the relevant traffic, then analyze, and
> >go from there.
>
> Yeah that what's I just did, and here are the results:
>
>
> May 27 20:09:31 localhost haproxy[9762]: <client_ip>:25907
> [27/May/2014:20:09:23.718]
> main backend/server02 7680/0/-1/-1/7680 503 212 - - CCVN 123/80/15/6/0
> 0/0
> {www.example.com|Mozilla/5.0 (Windows NT 6.1; WOW64)
> Appl|http://www.example.com/lang/bullshit}
> {|} "GET /lang/something/someone/somewhere/5804 HTTP/1.1"
>
>
> And this is corresponding tcpdump:
>
>
> 20:09:23.671542 IP source_ip.25907 > dest_ip.80: Flags [S], seq
> 3060464340, win 8192, options [mss 1452,nop,wscale 2,nop,nop,sackOK],
> length 0
> 20:09:23.671555 IP dest_ip.80 > source_ip.25907: Flags [S.], seq
> 2127273863, ack 3060464341, win 13600, options [mss
> 1360,nop,nop,sackOK,nop,wscale 7], length 0
> 20:09:23.718137 IP source_ip.25907 > dest_ip.80: Flags [.], ack 1, win
> 16660, length 0
> 20:09:31.397342 IP source_ip.25907 > dest_ip.80: Flags [.], seq 1:1361,
> ack 1, win 16660, length 1360
> 20:09:31.397360 IP dest_ip.80 > source_ip.25907: Flags [.], ack 1361,
> win 128, length 0
> 20:09:31.397672 IP source_ip.25907 > dest_ip.80: Flags [P.], seq
> 1361:1378, ack 1, win 16660, length 17
> 20:09:31.397681 IP dest_ip.80 > source_ip.25907: Flags [.], ack 1378,
> win 128, length 0
> 20:09:31.397792 IP source_ip.25907 > dest_ip.80: Flags [F.], seq 1378,
> ack 1, win 16660, length 0
> 20:09:31.397828 IP dest_ip.80 > source_ip.25907: Flags [F.], seq 1:213,
> ack 1379, win 128, length 212
> 20:09:31.456478 IP source_ip.25907 > dest_ip.80: Flags [R.], seq 1379,
> ack 213, win 0, length 0
>
>
> Now, haproxy logged 7680 miliseconds for Tc and Tt, and that exactly the
> timing of the connection.
>
> What I'm puzzled is why 7 sec halt in network traffic?
It could really be a site sucker. It first establishes connection pools
and distributes requests for objects found in pages across these pre-
established connections, then sends the reqeust and shutdown(SHUT_WR).
It is also possible that there is a high packet loss rate on the client
and that it took 7 seconds for it to manage to send its request after
establishing the connection! That could also be the consequence of a
bot saturating the client's link with many such requests.
Willy
