Re: excessive TCP duplicate acks?

Peter Jeremy wrote:
> On 2007-Jan-26 11:59:06 -0500, Andrew Gallatin <gallatin_at_cs.duke.edu> wrote:
> 
>>When running some benchmarks, I noticed tons of duplicate acks showing
>>up in systat -tcp (thousands, or tens of thousands per second).
> 
> 
> Whilst investigating other problems, I've just seen the same on 6.2.
> The following trace was taken on 192.168.234.1, which is running
> 6.2-RELEASE/i386 (with ipfilter enabled) with fxp (Intel 82559) NICs.
> 192.168.234.64 is running 6.2-STABLE/amd64 from late January (no
> firewall active) with a bge (Broadcom BCM5705 A3, ASIC rev. 0x3003)
> NIC and checksum offloading enabled.
> 
> The multiple SYN packets are due to a bug in the IPfilter state
> management, though it eventually allows a SYN through.  (And it is not
> totally unrealistic for multiple SYNs to be required before a SYN-ACK
> is received so this does not excuse the ACK flood).  Note that the
> duplicate ACKs are being sent from the host without a firewall so this
> does not appear to be related to ipfilter (or kern/102653).

This thing is really strange and difficult to debug.  A look at the CVS history
of tcp_input/output doesn't show any smoking gun.  ACKs like these are totally
pointless.  There are three places able to cause ACKs: 1) tcp_input decides to
call tcp_output [not the case here as there are no corresponding input packets
to cause this]; 2) tcp_output has a unterminated loop somewhere causing it to
spew the ACKs in rapid succession [unlikely as it holds the tcpcb lock and that
would block inbound packets]; 3) tcp timers are misfiring or not properly dis-
armed [here the logic in tcp_output may/should just ignore it and return w/o
sending any packet].

I haven't experienced this bug myself which makes it even harder to debug.

-- 
Andre

> The common factor seems to be amd64.
> 
> 08:11:59.725733 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp 58800221 0,sackOK,eol>
> 08:12:02.722826 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp 58803221 0,sackOK,eol>
> 08:12:05.922699 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,nop,wscale 1,nop,nop,timestamp 58806421 0,sackOK,eol>
> 08:12:09.122652 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
> 08:12:12.322614 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
> 08:12:15.522575 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
> 08:12:21.722501 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
> 08:12:33.922361 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
> 08:12:58.122057 IP 192.168.234.64.49195 > 192.168.234.1.22: S 3976363428:3976363428(0) win 65535 <mss 1460,sackOK,eol>
> 08:12:58.122596 IP 192.168.234.1.22 > 192.168.234.64.49195: S 3756522873:3756522873(0) ack 3976363429 win 65535 <mss 1460,sackOK,eol>
> 08:12:58.122775 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522874 win 65535
> 08:12:58.274044 IP 192.168.234.1.22 > 192.168.234.64.49195: P 3756522874:3756522913(39) ack 3976363429 win 65535
> 08:12:58.274285 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274347 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274393 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274434 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274478 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274521 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274562 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274607 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274645 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274688 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274727 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274766 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274801 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274835 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274873 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274907 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274941 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.274975 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275010 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275044 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275120 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275163 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275200 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275243 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275282 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275317 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275352 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275387 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275421 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275455 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275490 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275525 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275559 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275594 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275629 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275663 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275697 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275732 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275766 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.275801 IP 192.168.234.64.49195 > 192.168.234.1.22: P 3976363429:3976363468(39) ack 3756522913 win 65535
> 08:12:58.275838 IP 192.168.234.64.49195 > 192.168.234.1.22: P 3976363468:3976364220(752) ack 3756522913 win 65535
> 08:12:58.279466 IP 192.168.234.1.22 > 192.168.234.64.49195: . ack 3976364220 win 64909
> 08:12:58.279671 IP 192.168.234.64.49195 > 192.168.234.1.22: . ack 3756522913 win 65535
> 08:12:58.301824 IP 192.168.234.1.22 > 192.168.234.64.49195: P 3756522913:3756523657(744) ack 3976364220 win 64948
> 08:12:58.302362 IP 192.168.234.64.49195 > 192.168.234.1.22: P 3976364220:3976364244(24) ack 3756523657 win 65535
> 08:12:58.402330 IP 192.168.234.1.22 > 192.168.234.64.49195: . ack 3976364244 win 65535
>