Re: Spurious TCP retransmissions on ack vs kfree_skb reordering

On Fri, Feb 26, 2021 at 4:15 AM Jakub Kicinski [off-list ref] wrote:

On Thu, 25 Feb 2021 15:25:15 -0800 Jakub Kicinski wrote:

quoted

Hi!

We see large (4-8x) increase of what looks like TCP RTOs after rising
the Tx coalescing above Rx coalescing timeout.

Quick tracing of the events seems to indicate that the data has already
been acked when we enter tcp:tcp_retransmit_skb:

Seems like I'm pretty lost here and the tcp:tcp_retransmit_skb events
are less spurious than I thought. Looking at some tcpdump traces we see:

0.045277 IP6 A > B: Flags [SEW], seq 2248382925:2248383296, win 61920, options [mss 1440,sackOK,TS val 658870494 ecr 0,nop,wscale 11], length 371

0.045348 IP6 B > A: Flags [S.E], seq 961169456, ack 2248382926, win 65535, options [mss 1440,sackOK,TS val 883864022 ecr 658870494,nop,wscale 9], length 0

The SYNACK does not include the prior payload.

0.045369 IP6 A > B: Flags [P.], seq 1:372, ack 1, win 31, options [nop,nop,TS val 658870494 ecr 883864022], length 371

So this rtx is not spurious.

However in your prior email you wrote :

bytes_in:      0
bytes_out:   742
bytes_acked: 742

Are you sure that at the time of the retransmit, bytes_acked was 742 ?
I do not see how this could happen.

So looks potentially TFO related?

To try to count timeouts I run:

bpftrace --btf -e 'tracepoint:tcp:tcp_retransmit_skb {
  $icsk = (struct inet_connection_sock *)args->skaddr;
  if ($icsk->icsk_ca_state != 4) { return; }
  if ($icsk->icsk_pending)       { return; }

  printf(...);
}'

At tx-usecs coalescing of 25us I see 0 of those events.
At 100us there is a few.
At 200us there is a lot.