Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

We are seeing a crash in the TCP ACK codepath often in our regression
racks with an ARM64 device with 4.19 based kernel.

It appears that the tp->highest_ack is invalid when being accessed when 
a
FIN-ACK is received. In all the instances of the crash, the tcp socket
is in TCP_FIN_WAIT1 state.

[include/net/tcp.h]
static inline u32 tcp_highest_sack_seq(struct tcp_sock *tp)
{
	if (!tp->sacked_out)
		return tp->snd_una;

	if (tp->highest_sack == NULL)
		return tp->snd_nxt;

	return TCP_SKB_CB(tp->highest_sack)->seq;
}

[net/ipv4/tcp_input.c]
static int tcp_ack(struct sock *sk, const struct sk_buff *skb, int flag)
{
...
	prior_fack = tcp_is_sack(tp) ? tcp_highest_sack_seq(tp) : tp->snd_una;


Crash call stack below-

  16496.596106:   <6> Unable to handle kernel paging request at virtual 
address fffffff2cd81a368
  16496.730771:   <2> pc : tcp_ack+0x174/0x11e8
  16496.734536:   <2> lr : tcp_rcv_state_process+0x318/0x1300
  16497.183109:   <2> Call trace:
  16497.183114:   <2>  tcp_ack+0x174/0x11e8
  16497.183115:   <2>  tcp_rcv_state_process+0x318/0x1300
  16497.183117:   <2>  tcp_v4_do_rcv+0x1a8/0x1f0
  16497.183118:   <2>  tcp_v4_rcv+0xe90/0xec8
  16497.183120:   <2>  ip_protocol_deliver_rcu+0x150/0x298
  16497.183121:   <2>  ip_local_deliver+0x21c/0x2a8
  16497.183122:   <2>  ip_rcv+0x1c4/0x210
  16497.183124:   <2>  __netif_receive_skb_core+0xab0/0xd90
  16497.183125:   <2>  netif_receive_skb_internal+0x12c/0x368
  16497.183126:   <2>  napi_gro_receive+0x1e0/0x290

Is it expected for the tp->highest_ack to be
accessed in this state?

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Neal Cardwell]

tcp_write_queue_purgeOn Sun, Oct 20, 2019 at 4:25 PM Subash Abhinov
Kasiviswanathan <subashab@codeaurora.org> wrote:
>
> We are seeing a crash in the TCP ACK codepath often in our regression
> racks with an ARM64 device with 4.19 based kernel.
>
> It appears that the tp->highest_ack is invalid when being accessed when
> a
> FIN-ACK is received. In all the instances of the crash, the tcp socket
> is in TCP_FIN_WAIT1 state.

Hmm. Random related thought while searching for a possible cause: I
wonder if tcp_write_queue_purge() should clear tp->highest_sack (and
possibly tp->sacked_out)? The tcp_write_queue_purge() code is careful
to call  tcp_clear_all_retrans_hints(tcp_sk(sk)) and I would imagine
that similar considerations would imply that we should clear at least
tp->highest_sack?

neal

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

> Hmm. Random related thought while searching for a possible cause: I
> wonder if tcp_write_queue_purge() should clear tp->highest_sack (and
> possibly tp->sacked_out)? The tcp_write_queue_purge() code is careful
> to call  tcp_clear_all_retrans_hints(tcp_sk(sk)) and I would imagine
> that similar considerations would imply that we should clear at least
> tp->highest_sack?
> 
> neal

Hi Neal

If the socket is in FIN-WAIT1, does that mean that all the segments
corresponding to SACK blocks are sent and ACKed already?

tp->sacked_out is non zero in all these crashes (is the SACK information
possibly invalid or stale here?).

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Neal Cardwell]

On Sun, Oct 20, 2019 at 7:15 PM Subash Abhinov Kasiviswanathan
<subashab@codeaurora.org> wrote:
>
> > Hmm. Random related thought while searching for a possible cause: I
> > wonder if tcp_write_queue_purge() should clear tp->highest_sack (and
> > possibly tp->sacked_out)? The tcp_write_queue_purge() code is careful
> > to call  tcp_clear_all_retrans_hints(tcp_sk(sk)) and I would imagine
> > that similar considerations would imply that we should clear at least
> > tp->highest_sack?
> >
> > neal
>
> Hi Neal
>
> If the socket is in FIN-WAIT1, does that mean that all the segments
> corresponding to SACK blocks are sent and ACKed already?

FIN-WAIT1 just means the local application has called close() or
shutdown() to shut down the sending direction of the socket, and the
local TCP stack has sent a FIN, and is waiting to receive a FIN and an
ACK from the other side (in either order, or simultaneously). The
ASCII art state transition diagram on page 22 of RFC 793 (e.g.
https://tools.ietf.org/html/rfc793#section-3.2 ) is one source for
this, though the W. Richard Stevens books have a much more readable
diagram.

There may still be unacked and SACKed data in the retransmit queue at
this point.

> tp->sacked_out is non zero in all these crashes

Thanks, that is a useful data point. Do you know what particular value
 tp->sacked_out has? Would you be able to capture/log the value of
tp->packets_out, tp->lost_out, and tp->retrans_out as well?

> (is the SACK information possibly invalid or stale here?).

Yes, one guess would be that somehow the skbs in the retransmit queue
have been freed, but tp->sacked_out is still non-zero and
tp->highest_sack is still a dangling pointer into one of those freed
skbs. The tcp_write_queue_purge() function is one function that fees
the skbs in the retransmit queue and leaves tp->sacked_out as non-zero
and  tp->highest_sack as a dangling pointer to a freed skb, AFAICT, so
that's why I'm wondering about that function. I can't think of a
specific sequence of events that would involve tcp_write_queue_purge()
and then a socket that's still in FIN-WAIT1. Maybe I'm not being
creative enough, or maybe that guess is on the wrong track. Would you
be able to set a new bit in the tcp_sock in tcp_write_queue_purge()
and log it in your instrumentation point, to see if
tcp_write_queue_purge()  was called for these connections that cause
this crash?

thanks,
neal

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

> FIN-WAIT1 just means the local application has called close() or
> shutdown() to shut down the sending direction of the socket, and the
> local TCP stack has sent a FIN, and is waiting to receive a FIN and an
> ACK from the other side (in either order, or simultaneously). The
> ASCII art state transition diagram on page 22 of RFC 793 (e.g.
> https://tools.ietf.org/html/rfc793#section-3.2 ) is one source for
> this, though the W. Richard Stevens books have a much more readable
> diagram.
> 
> There may still be unacked and SACKed data in the retransmit queue at
> this point.
> 

Thanks for the clarification.

> Thanks, that is a useful data point. Do you know what particular value
>  tp->sacked_out has? Would you be able to capture/log the value of
> tp->packets_out, tp->lost_out, and tp->retrans_out as well?
> 

tp->sacket_out varies per crash instance - 55, 180 etc.
However the other values are always the same - tp->packets_out is 0,
tp->lost_out is 1 and tp->retrans_out is 1.

> Yes, one guess would be that somehow the skbs in the retransmit queue
> have been freed, but tp->sacked_out is still non-zero and
> tp->highest_sack is still a dangling pointer into one of those freed
> skbs. The tcp_write_queue_purge() function is one function that fees
> the skbs in the retransmit queue and leaves tp->sacked_out as non-zero
> and  tp->highest_sack as a dangling pointer to a freed skb, AFAICT, so
> that's why I'm wondering about that function. I can't think of a
> specific sequence of events that would involve tcp_write_queue_purge()
> and then a socket that's still in FIN-WAIT1. Maybe I'm not being
> creative enough, or maybe that guess is on the wrong track. Would you
> be able to set a new bit in the tcp_sock in tcp_write_queue_purge()
> and log it in your instrumentation point, to see if
> tcp_write_queue_purge()  was called for these connections that cause
> this crash?

Sure, I can try this out.

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Neal Cardwell]

On Sun, Oct 20, 2019 at 10:45 PM Subash Abhinov Kasiviswanathan
<subashab@codeaurora.org> wrote:
>
> > FIN-WAIT1 just means the local application has called close() or
> > shutdown() to shut down the sending direction of the socket, and the
> > local TCP stack has sent a FIN, and is waiting to receive a FIN and an
> > ACK from the other side (in either order, or simultaneously). The
> > ASCII art state transition diagram on page 22 of RFC 793 (e.g.
> > https://tools.ietf.org/html/rfc793#section-3.2 ) is one source for
> > this, though the W. Richard Stevens books have a much more readable
> > diagram.
> >
> > There may still be unacked and SACKed data in the retransmit queue at
> > this point.
> >
>
> Thanks for the clarification.
>
> > Thanks, that is a useful data point. Do you know what particular value
> >  tp->sacked_out has? Would you be able to capture/log the value of
> > tp->packets_out, tp->lost_out, and tp->retrans_out as well?
> >
>
> tp->sacket_out varies per crash instance - 55, 180 etc.
> However the other values are always the same - tp->packets_out is 0,
> tp->lost_out is 1 and tp->retrans_out is 1.

Interesting! As tcp_input.c summarizes, "packets_out is
SND.NXT-SND.UNA counted in packets". In the normal operation of a
socket, tp->packets_out should not be 0 if any of those other fields
are non-zero.

The tcp_write_queue_purge() function sets packets_out to 0:

  https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git/tree/net/ipv4/tcp.c?h=v4.19#n2526

So the execution of tcp_write_queue_purge()  before this point is one
way for the socket to end up in this weird state.

> > Yes, one guess would be that somehow the skbs in the retransmit queue
> > have been freed, but tp->sacked_out is still non-zero and
> > tp->highest_sack is still a dangling pointer into one of those freed
> > skbs. The tcp_write_queue_purge() function is one function that fees
> > the skbs in the retransmit queue and leaves tp->sacked_out as non-zero
> > and  tp->highest_sack as a dangling pointer to a freed skb, AFAICT, so
> > that's why I'm wondering about that function. I can't think of a
> > specific sequence of events that would involve tcp_write_queue_purge()
> > and then a socket that's still in FIN-WAIT1. Maybe I'm not being
> > creative enough, or maybe that guess is on the wrong track. Would you
> > be able to set a new bit in the tcp_sock in tcp_write_queue_purge()
> > and log it in your instrumentation point, to see if
> > tcp_write_queue_purge()  was called for these connections that cause
> > this crash?
>
> Sure, I can try this out.

Great! Thanks!

neal

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

> Interesting! As tcp_input.c summarizes, "packets_out is
> SND.NXT-SND.UNA counted in packets". In the normal operation of a
> socket, tp->packets_out should not be 0 if any of those other fields
> are non-zero.
> 
> The tcp_write_queue_purge() function sets packets_out to 0:
> 
> 
> https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git/tree/net/ipv4/tcp.c?h=v4.19#n2526
> 
> So the execution of tcp_write_queue_purge()  before this point is one
> way for the socket to end up in this weird state.
> 

In one of the instances, the values are tp->snd_nxt = 1016118098,
tp->snd_una = 1016047820

tp->mss_cache = 1378

I assume the number of outstanding segments should be
(tp->snd_nxt - tp->snd_una)/tp->mss_cache = 51

tp->packets_out = 0 and tp->sacked_out = 158 in this case.

>> > Yes, one guess would be that somehow the skbs in the retransmit queue
>> > have been freed, but tp->sacked_out is still non-zero and
>> > tp->highest_sack is still a dangling pointer into one of those freed
>> > skbs. The tcp_write_queue_purge() function is one function that fees
>> > the skbs in the retransmit queue and leaves tp->sacked_out as non-zero
>> > and  tp->highest_sack as a dangling pointer to a freed skb, AFAICT, so
>> > that's why I'm wondering about that function. I can't think of a
>> > specific sequence of events that would involve tcp_write_queue_purge()
>> > and then a socket that's still in FIN-WAIT1. Maybe I'm not being
>> > creative enough, or maybe that guess is on the wrong track. Would you
>> > be able to set a new bit in the tcp_sock in tcp_write_queue_purge()
>> > and log it in your instrumentation point, to see if
>> > tcp_write_queue_purge()  was called for these connections that cause
>> > this crash?

I've queued up a build which logs calls to tcp_write_queue_purge and
clears tp->highest_sack and tp->sacked_out. I will let you know how
it fares by end of week.

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Neal Cardwell]

On Mon, Oct 21, 2019 at 8:04 PM Subash Abhinov Kasiviswanathan
<subashab@codeaurora.org> wrote:
>
> > Interesting! As tcp_input.c summarizes, "packets_out is
> > SND.NXT-SND.UNA counted in packets". In the normal operation of a
> > socket, tp->packets_out should not be 0 if any of those other fields
> > are non-zero.
> >
> > The tcp_write_queue_purge() function sets packets_out to 0:
> >
> >
> > https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git/tree/net/ipv4/tcp.c?h=v4.19#n2526
> >
> > So the execution of tcp_write_queue_purge()  before this point is one
> > way for the socket to end up in this weird state.
> >
>
> In one of the instances, the values are tp->snd_nxt = 1016118098,
> tp->snd_una = 1016047820
>
> tp->mss_cache = 1378
>
> I assume the number of outstanding segments should be
> (tp->snd_nxt - tp->snd_una)/tp->mss_cache = 51

That would be a good expectation if all the packets were full-sized.

> tp->packets_out = 0 and tp->sacked_out = 158 in this case.

OK, thanks. It could be that sacked_out is reasonable and some of the
packets were not full-sized. But, as discussed above, typically the
packets_out should not be 0 if sacked_out is non-zero (with at least
the exception of the tcp_write_queue_purge()  case).

> >> > Yes, one guess would be that somehow the skbs in the retransmit queue
> >> > have been freed, but tp->sacked_out is still non-zero and
> >> > tp->highest_sack is still a dangling pointer into one of those freed
> >> > skbs. The tcp_write_queue_purge() function is one function that fees
> >> > the skbs in the retransmit queue and leaves tp->sacked_out as non-zero
> >> > and  tp->highest_sack as a dangling pointer to a freed skb, AFAICT, so
> >> > that's why I'm wondering about that function. I can't think of a
> >> > specific sequence of events that would involve tcp_write_queue_purge()
> >> > and then a socket that's still in FIN-WAIT1. Maybe I'm not being
> >> > creative enough, or maybe that guess is on the wrong track. Would you
> >> > be able to set a new bit in the tcp_sock in tcp_write_queue_purge()
> >> > and log it in your instrumentation point, to see if
> >> > tcp_write_queue_purge()  was called for these connections that cause
> >> > this crash?
>
> I've queued up a build which logs calls to tcp_write_queue_purge and
> clears tp->highest_sack and tp->sacked_out. I will let you know how
> it fares by end of week.

OK, thanks. That should be a useful data point.

cheers,
neal

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

>> I've queued up a build which logs calls to tcp_write_queue_purge and
>> clears tp->highest_sack and tp->sacked_out. I will let you know how
>> it fares by end of week.
> 
> OK, thanks. That should be a useful data point.

I haven't seen the crash in the testing so far.
Looks like clearing these values seems to help.

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Neal Cardwell]

On Mon, Oct 28, 2019 at 9:36 PM Subash Abhinov Kasiviswanathan
<subashab@codeaurora.org> wrote:
>
> >> I've queued up a build which logs calls to tcp_write_queue_purge and
> >> clears tp->highest_sack and tp->sacked_out. I will let you know how
> >> it fares by end of week.
> >
> > OK, thanks. That should be a useful data point.
>
> I haven't seen the crash in the testing so far.
> Looks like clearing these values seems to help.

Thanks. Do you mind sharing what your patch looked like, so we can
understand precisely what was changed?

Also, are you able to share what the workload looked like that tickled
this issue? (web client? file server?...)

thanks,
neal

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

> Thanks. Do you mind sharing what your patch looked like, so we can
> understand precisely what was changed?
> 
> Also, are you able to share what the workload looked like that tickled
> this issue? (web client? file server?...)

Sure. This was seen only on our regression racks and the workload there
is a combination of FTP, browsing and other apps.

diff --git a/include/linux/tcp.h b/include/linux/tcp.h
index 4374196..9af7497 100644
--- a/include/linux/tcp.h
+++ b/include/linux/tcp.h
@@ -232,7 +232,8 @@ struct tcp_sock {
                 fastopen_connect:1, /* FASTOPEN_CONNECT sockopt */
                 fastopen_no_cookie:1, /* Allow send/recv SYN+data 
without a cookie */
                 is_sack_reneg:1,    /* in recovery from loss with SACK 
reneg? */
-               unused:2;
+               unused:1,
+               wqp_called:1;
         u8      nonagle     : 4,/* Disable Nagle algorithm?             
*/
                 thin_lto    : 1,/* Use linear timeouts for thin streams 
*/
                 recvmsg_inq : 1,/* Indicate # of bytes in queue upon 
recvmsg */
diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
index 1a1fcb3..0c29bdd 100644
--- a/net/ipv4/tcp.c
+++ b/net/ipv4/tcp.c
@@ -2534,6 +2534,9 @@ void tcp_write_queue_purge(struct sock *sk)
         INIT_LIST_HEAD(&tcp_sk(sk)->tsorted_sent_queue);
         sk_mem_reclaim(sk);
         tcp_clear_all_retrans_hints(tcp_sk(sk));
+       tcp_sk(sk)->highest_sack = NULL;
+       tcp_sk(sk)->sacked_out = 0;
+       tcp_sk(sk)->wqp_called = 1;
         tcp_sk(sk)->packets_out = 0;
         inet_csk(sk)->icsk_backoff = 0;
  }


-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Josh Hunt]

On 10/30/19 11:27 AM, Subash Abhinov Kasiviswanathan wrote:
>> Thanks. Do you mind sharing what your patch looked like, so we can
>> understand precisely what was changed?
>>
>> Also, are you able to share what the workload looked like that tickled
>> this issue? (web client? file server?...)
> 
> Sure. This was seen only on our regression racks and the workload there
> is a combination of FTP, browsing and other apps.
> 
> diff --git a/include/linux/tcp.h b/include/linux/tcp.h
> index 4374196..9af7497 100644
> --- a/include/linux/tcp.h
> +++ b/include/linux/tcp.h
> @@ -232,7 +232,8 @@ struct tcp_sock {
>                  fastopen_connect:1, /* FASTOPEN_CONNECT sockopt */
>                  fastopen_no_cookie:1, /* Allow send/recv SYN+data 
> without a cookie */
>                  is_sack_reneg:1,    /* in recovery from loss with SACK 
> reneg? */
> -               unused:2;
> +               unused:1,
> +               wqp_called:1;
>          u8      nonagle     : 4,/* Disable Nagle algorithm? */
>                  thin_lto    : 1,/* Use linear timeouts for thin streams */
>                  recvmsg_inq : 1,/* Indicate # of bytes in queue upon 
> recvmsg */
> diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
> index 1a1fcb3..0c29bdd 100644
> --- a/net/ipv4/tcp.c
> +++ b/net/ipv4/tcp.c
> @@ -2534,6 +2534,9 @@ void tcp_write_queue_purge(struct sock *sk)
>          INIT_LIST_HEAD(&tcp_sk(sk)->tsorted_sent_queue);
>          sk_mem_reclaim(sk);
>          tcp_clear_all_retrans_hints(tcp_sk(sk));
> +       tcp_sk(sk)->highest_sack = NULL;
> +       tcp_sk(sk)->sacked_out = 0;
> +       tcp_sk(sk)->wqp_called = 1;
>          tcp_sk(sk)->packets_out = 0;
>          inet_csk(sk)->icsk_backoff = 0;
>   }
> 
> 

Neal

Since tcp_write_queue_purge() calls tcp_rtx_queue_purge() and we're 
deleting everything in the retrans queue there, doesn't it make sense to 
zero out all of those associated counters? Obviously clearing sacked_out 
is helping here, but is there a reason to keep track of lost_out, 
retrans_out, etc if retrans queue is now empty? Maybe calling 
tcp_clear_retrans() from tcp_rtx_queue_purge() ?

Josh

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Eric Dumazet]

On 10/30/19 2:48 PM, Josh Hunt wrote:
> On 10/30/19 11:27 AM, Subash Abhinov Kasiviswanathan wrote:
>>> Thanks. Do you mind sharing what your patch looked like, so we can
>>> understand precisely what was changed?
>>>
>>> Also, are you able to share what the workload looked like that tickled
>>> this issue? (web client? file server?...)
>>
>> Sure. This was seen only on our regression racks and the workload there
>> is a combination of FTP, browsing and other apps.
>>
>> diff --git a/include/linux/tcp.h b/include/linux/tcp.h
>> index 4374196..9af7497 100644
>> --- a/include/linux/tcp.h
>> +++ b/include/linux/tcp.h
>> @@ -232,7 +232,8 @@ struct tcp_sock {
>>                  fastopen_connect:1, /* FASTOPEN_CONNECT sockopt */
>>                  fastopen_no_cookie:1, /* Allow send/recv SYN+data without a cookie */
>>                  is_sack_reneg:1,    /* in recovery from loss with SACK reneg? */
>> -               unused:2;
>> +               unused:1,
>> +               wqp_called:1;
>>          u8      nonagle     : 4,/* Disable Nagle algorithm? */
>>                  thin_lto    : 1,/* Use linear timeouts for thin streams */
>>                  recvmsg_inq : 1,/* Indicate # of bytes in queue upon recvmsg */
>> diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
>> index 1a1fcb3..0c29bdd 100644
>> --- a/net/ipv4/tcp.c
>> +++ b/net/ipv4/tcp.c
>> @@ -2534,6 +2534,9 @@ void tcp_write_queue_purge(struct sock *sk)
>>          INIT_LIST_HEAD(&tcp_sk(sk)->tsorted_sent_queue);
>>          sk_mem_reclaim(sk);
>>          tcp_clear_all_retrans_hints(tcp_sk(sk));
>> +       tcp_sk(sk)->highest_sack = NULL;
>> +       tcp_sk(sk)->sacked_out = 0;
>> +       tcp_sk(sk)->wqp_called = 1;
>>          tcp_sk(sk)->packets_out = 0;
>>          inet_csk(sk)->icsk_backoff = 0;
>>   }
>>
>>
> 
> Neal
> 
> Since tcp_write_queue_purge() calls tcp_rtx_queue_purge() and we're deleting everything in the retrans queue there, doesn't it make sense to zero out all of those associated counters? Obviously clearing sacked_out is helping here, but is there a reason to keep track of lost_out, retrans_out, etc if retrans queue is now empty? Maybe calling tcp_clear_retrans() from tcp_rtx_queue_purge() ?

First, I would like to understand if we hit this problem on current upstream kernels.

Maybe a backport forgot a dependency.

tcp_write_queue_purge() calls tcp_clear_all_retrans_hints(), not tcp_clear_retrans(),
this is probably for a reason.

Brute force clearing these fields might hide a serious bug.

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Eric Dumazet]

On 10/30/19 6:27 PM, Eric Dumazet wrote:
> 
> 
> On 10/30/19 2:48 PM, Josh Hunt wrote:
>> On 10/30/19 11:27 AM, Subash Abhinov Kasiviswanathan wrote:
>>>> Thanks. Do you mind sharing what your patch looked like, so we can
>>>> understand precisely what was changed?
>>>>
>>>> Also, are you able to share what the workload looked like that tickled
>>>> this issue? (web client? file server?...)
>>>
>>> Sure. This was seen only on our regression racks and the workload there
>>> is a combination of FTP, browsing and other apps.
>>>
>>> diff --git a/include/linux/tcp.h b/include/linux/tcp.h
>>> index 4374196..9af7497 100644
>>> --- a/include/linux/tcp.h
>>> +++ b/include/linux/tcp.h
>>> @@ -232,7 +232,8 @@ struct tcp_sock {
>>>                  fastopen_connect:1, /* FASTOPEN_CONNECT sockopt */
>>>                  fastopen_no_cookie:1, /* Allow send/recv SYN+data without a cookie */
>>>                  is_sack_reneg:1,    /* in recovery from loss with SACK reneg? */
>>> -               unused:2;
>>> +               unused:1,
>>> +               wqp_called:1;
>>>          u8      nonagle     : 4,/* Disable Nagle algorithm? */
>>>                  thin_lto    : 1,/* Use linear timeouts for thin streams */
>>>                  recvmsg_inq : 1,/* Indicate # of bytes in queue upon recvmsg */
>>> diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
>>> index 1a1fcb3..0c29bdd 100644
>>> --- a/net/ipv4/tcp.c
>>> +++ b/net/ipv4/tcp.c
>>> @@ -2534,6 +2534,9 @@ void tcp_write_queue_purge(struct sock *sk)
>>>          INIT_LIST_HEAD(&tcp_sk(sk)->tsorted_sent_queue);
>>>          sk_mem_reclaim(sk);
>>>          tcp_clear_all_retrans_hints(tcp_sk(sk));
>>> +       tcp_sk(sk)->highest_sack = NULL;
>>> +       tcp_sk(sk)->sacked_out = 0;
>>> +       tcp_sk(sk)->wqp_called = 1;
>>>          tcp_sk(sk)->packets_out = 0;
>>>          inet_csk(sk)->icsk_backoff = 0;
>>>   }
>>>
>>>
>>
>> Neal
>>
>> Since tcp_write_queue_purge() calls tcp_rtx_queue_purge() and we're deleting everything in the retrans queue there, doesn't it make sense to zero out all of those associated counters? Obviously clearing sacked_out is helping here, but is there a reason to keep track of lost_out, retrans_out, etc if retrans queue is now empty? Maybe calling tcp_clear_retrans() from tcp_rtx_queue_purge() ?
> 
> First, I would like to understand if we hit this problem on current upstream kernels.
> 
> Maybe a backport forgot a dependency.
> 
> tcp_write_queue_purge() calls tcp_clear_all_retrans_hints(), not tcp_clear_retrans(),
> this is probably for a reason.
> 
> Brute force clearing these fields might hide a serious bug.
> 

I guess we are all too busy to get more understanding on this :/

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[subashab]

>>> Since tcp_write_queue_purge() calls tcp_rtx_queue_purge() and we're 
>>> deleting everything in the retrans queue there, doesn't it make sense 
>>> to zero out all of those associated counters? Obviously clearing 
>>> sacked_out is helping here, but is there a reason to keep track of 
>>> lost_out, retrans_out, etc if retrans queue is now empty? Maybe 
>>> calling tcp_clear_retrans() from tcp_rtx_queue_purge() ?
>> 
>> First, I would like to understand if we hit this problem on current 
>> upstream kernels.
>> 
>> Maybe a backport forgot a dependency.
>> 
>> tcp_write_queue_purge() calls tcp_clear_all_retrans_hints(), not 
>> tcp_clear_retrans(),
>> this is probably for a reason.
>> 
>> Brute force clearing these fields might hide a serious bug.
>> 
> 
> I guess we are all too busy to get more understanding on this :/

Our test devices are on 4.19.x and it is not possible to switch to a 
newer
version. Perhaps Josh has seen this on a newer kernel.

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Avinash Patil]

Hi Eric,

This crash looks quite similar to the one I am experiencing [1] and
reported already.

[1] https://www.spinics.net/lists/netdev/msg611694.html

Thanks,
Avinash

On Fri, Nov 29, 2019 at 6:52 PM <subashab@codeaurora.org> wrote:
>
> >>> Since tcp_write_queue_purge() calls tcp_rtx_queue_purge() and we're
> >>> deleting everything in the retrans queue there, doesn't it make sense
> >>> to zero out all of those associated counters? Obviously clearing
> >>> sacked_out is helping here, but is there a reason to keep track of
> >>> lost_out, retrans_out, etc if retrans queue is now empty? Maybe
> >>> calling tcp_clear_retrans() from tcp_rtx_queue_purge() ?
> >>
> >> First, I would like to understand if we hit this problem on current
> >> upstream kernels.
> >>
> >> Maybe a backport forgot a dependency.
> >>
> >> tcp_write_queue_purge() calls tcp_clear_all_retrans_hints(), not
> >> tcp_clear_retrans(),
> >> this is probably for a reason.
> >>
> >> Brute force clearing these fields might hide a serious bug.
> >>
> >
> > I guess we are all too busy to get more understanding on this :/
>
> Our test devices are on 4.19.x and it is not possible to switch to a
> newer
> version. Perhaps Josh has seen this on a newer kernel.

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Eric Dumazet]

On 11/29/19 9:39 PM, Avinash Patil wrote:
> Hi Eric,
> 
> This crash looks quite similar to the one I am experiencing [1] and
> reported already.
> 
> [1] https://www.spinics.net/lists/netdev/msg611694.html
>

Please start a bisection.

Thanks you.

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Josh Hunt]

On 11/29/19 6:51 PM, subashab@codeaurora.org wrote:
>>>> Since tcp_write_queue_purge() calls tcp_rtx_queue_purge() and we're 
>>>> deleting everything in the retrans queue there, doesn't it make 
>>>> sense to zero out all of those associated counters? Obviously 
>>>> clearing sacked_out is helping here, but is there a reason to keep 
>>>> track of lost_out, retrans_out, etc if retrans queue is now empty? 
>>>> Maybe calling tcp_clear_retrans() from tcp_rtx_queue_purge() ?
>>>
>>> First, I would like to understand if we hit this problem on current 
>>> upstream kernels.
>>>
>>> Maybe a backport forgot a dependency.
>>>
>>> tcp_write_queue_purge() calls tcp_clear_all_retrans_hints(), not 
>>> tcp_clear_retrans(),
>>> this is probably for a reason.
>>>
>>> Brute force clearing these fields might hide a serious bug.
>>>
>>
>> I guess we are all too busy to get more understanding on this :/
> 
> Our test devices are on 4.19.x and it is not possible to switch to a newer
> version. Perhaps Josh has seen this on a newer kernel.

Sorry I've been out of town without email access. To be clear I've never 
seen this crash. I've only noticed that we do not clear some counters 
when we clear out the retransmit queue and this caught my eye when 
debugging another unrelated issue. I will try and get some cycles this 
week to instrument a kernel and reproduce the behavior I was seeing. My 
concern IIRC was more around tcp_left_out() being > packets_out and 
retrans_out causing tcp_packets_in_flight() to wrap. Anyway I'll report 
my findings on this thread if they seem relevant otherwise maybe I'll 
start another discussion thread. I don't want to pollute this one with 
my ramblings...

Josh

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Eric Dumazet]

On 10/30/19 11:27 AM, Subash Abhinov Kasiviswanathan wrote:
>> Thanks. Do you mind sharing what your patch looked like, so we can
>> understand precisely what was changed?
>>
>> Also, are you able to share what the workload looked like that tickled
>> this issue? (web client? file server?...)
> 
> Sure. This was seen only on our regression racks and the workload there
> is a combination of FTP, browsing and other apps.
> 
> diff --git a/include/linux/tcp.h b/include/linux/tcp.h
> index 4374196..9af7497 100644
> --- a/include/linux/tcp.h
> +++ b/include/linux/tcp.h
> @@ -232,7 +232,8 @@ struct tcp_sock {
>                 fastopen_connect:1, /* FASTOPEN_CONNECT sockopt */
>                 fastopen_no_cookie:1, /* Allow send/recv SYN+data without a cookie */
>                 is_sack_reneg:1,    /* in recovery from loss with SACK reneg? */
> -               unused:2;
> +               unused:1,
> +               wqp_called:1;
>         u8      nonagle     : 4,/* Disable Nagle algorithm?             */
>                 thin_lto    : 1,/* Use linear timeouts for thin streams */
>                 recvmsg_inq : 1,/* Indicate # of bytes in queue upon recvmsg */
> diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
> index 1a1fcb3..0c29bdd 100644
> --- a/net/ipv4/tcp.c
> +++ b/net/ipv4/tcp.c
> @@ -2534,6 +2534,9 @@ void tcp_write_queue_purge(struct sock *sk)
>         INIT_LIST_HEAD(&tcp_sk(sk)->tsorted_sent_queue);
>         sk_mem_reclaim(sk);
>         tcp_clear_all_retrans_hints(tcp_sk(sk));
> +       tcp_sk(sk)->highest_sack = NULL;
> +       tcp_sk(sk)->sacked_out = 0;
> +       tcp_sk(sk)->wqp_called = 1;

What is this wqp_called exactly ?

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

> What is this wqp_called exactly ?

This was just a debug to ensure that tcp_write_queue_purge()
was called. In case the same crash was seen with the patch,
this bit would atleast tell whether this function was invoked or not.

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Eric Dumazet]

On 10/20/19 1:25 PM, Subash Abhinov Kasiviswanathan wrote:
> We are seeing a crash in the TCP ACK codepath often in our regression
> racks with an ARM64 device with 4.19 based kernel.
> 

Please give us a pointer to the exact git tree and sha1.

I do not analyze TCP stack problems without an exact starting point,
or at least a crystal ball, which I do not have.

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Subash Abhinov Kasiviswanathan]

> Please give us a pointer to the exact git tree and sha1.
> 
> I do not analyze TCP stack problems without an exact starting point,
> or at least a crystal ball, which I do not have.

Hi Eric

We are at this commit - Merge 4.19.75 into android-4.19-q.

https://android.googlesource.com/kernel/common/+/cfe571e421ab873403a8f75413e04ecf5bf7e393

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project

Re: Crash when receiving FIN-ACK in TCP_FIN_WAIT1 state

[Josh Hunt]

On Mon, Oct 21, 2019 at 10:42 AM Subash Abhinov Kasiviswanathan
<subashab@codeaurora.org> wrote:
>
> > Please give us a pointer to the exact git tree and sha1.
> >
> > I do not analyze TCP stack problems without an exact starting point,
> > or at least a crystal ball, which I do not have.
>
> Hi Eric
>
> We are at this commit - Merge 4.19.75 into android-4.19-q.
>
> https://android.googlesource.com/kernel/common/+/cfe571e421ab873403a8f75413e04ecf5bf7e393
>
> --
> Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
> a Linux Foundation Collaborative Project

We were investigating a problem in this area a few months back (it
turned out to be something else), but were wondering if retrans_out,
lost_out, and sacked_out should be cleared in tcp_rtx_queue_purge()? I
meant to get back to it, but it got buried and this just thread jogged
my memory...

-- 
Josh