Hi Finn Arne,
On Tue, Feb 25, 2014 at 03:17:24PM +0100, Finn Arne Gangstad wrote:
> Slowly upgrading some load balancers with the latest snapshots, and we get
> a lot of CL entries in our logs, this caused some people to get a bit
> scared.
>
> Typical tcp dump:
>
> 13:58:55.161381 IP x.x.x.x.39812 > y.y.y.y.80: Flags [S], seq 1448645292,
> win 5840, options [mss 1380,sackOK,TS val 231360268 ecr 0,nop,wscale
> 3,nop,nop,nop,nop,nop,nop,nop,nop,nop,nop,nop,nop,nop,nop,nop,eol], length 0
> 13:58:55.161388 IP y.y.y.y.80 > x.x.x.x.39812: Flags [S.], seq 1513888944,
> ack 1448645293, win 14480, options [mss 1460,sackOK,TS val 356930492 ecr
> 231360268,nop,wscale 8], length 0
> 13:58:55.304307 IP x.x.x.x.39812 > y.y.y.y.80: Flags [.], ack 1, win 730,
> options [nop,nop,TS val 231360282 ecr 356930492], length 0
> 13:58:55.312272 IP y.y.y.y.80 > x.x.x.x.39812: Flags [F.], seq 1:161, ack
> 897, win 64, options [nop,nop,TS val 356930530 ecr 231360282], length 160
> 13:58:55.456120 IP x.x.x.x.39812 > y.y.y.y.80: Flags [.], ack 162, win 804,
> options [nop,nop,TS val 231360297 ecr 356930530], length 0
> 13:58:55.456903 IP x.x.x.x.39812 > y.y.y.y.80: Flags [R.], seq 897, ack
> 162, win 804, options [nop,nop,TS val 231360297 ecr 356930530], length 0
>
> Causes a log entry like this:
>
> 2014-02-25T13:58:55+00:00 xxx haproxy[1723059]: x.x.x.x:39812
> [25/Feb/2014:13:58:55.311] http_proxy fe/be 0/0/0/1/145 301 160 - - CL--
> 40322/40322/0/0/0 0/0 {|} "GET /... HTTP/1.1"
It is normal. In the past it was not possible to know this, reason why
it was not logged. Here for haproxy there is no way to know if the client
retrieved the whole response or not because the TCP stack has likely only
reported the reset. All haproxy knows is that it received a reset in
response to the *last* segment (hence 'L'). Normally this is OK if it's
the client which did this. But when it's a firewall, router or bogus
load balancer which randomly does this due to some packets not matching
an expired session, I guess you'll be happy to have this useful
information to help troubleshoot the issue !
BTW, if you can run "strace -tt" on haproxy in parallel to your trace,
we'll see if we can find a hint to differenciate this termination from
a real reset. But I must confess that I really don't see what could
help here. Also, with some fast clients or over some high latency
links you may even only receive the RST thus have no information to
differenciate the two.
Best regards,
Willy
