tcp crash in net-2.6 tree

tcp crash in net-2.6 tree

[Andrew Morton]

Full -mm lineup.  The x86_64 box was acting as a distcc server at the time.

Nothing hit the logs, I'm afraid.  But almost all the info is in
http://userweb.kernel.org/~akpm/s5000494.jpg


<pokes around in gdb a bit>

It died in tcp_update_scoreboard_fack() here:

                if ((!IsFack(tp) || !tcp_skb_timedout(sk, skb)) &&
                    after(TCP_SKB_CB(skb)->seq, tp->high_seq)) {
                        /* RFC: should we have find_below? */
                        skb = tcp_write_queue_find(sk, tp->high_seq);
                        not_marked_skb = skb;
                        skb = tcp_write_queue_prev(sk, skb);
                        /* Timedout top is again uncertain? */
                        if (tcp_skb_timedout(sk, skb))
                                timedout_continue = 1;
                }


(gdb) l *0xffffffff8048ded8
0xffffffff8048ded8 is in tcp_update_scoreboard_fack (include/net/tcp.h:1197).
1192            return skb->next;
1193    }
1194    
1195    static inline struct sk_buff *tcp_write_queue_prev(struct sock *sk, struct sk_buff *skb)
1196    {
1197            return skb->prev;
1198    }
1199    
1200    #define tcp_for_write_queue(skb, sk)                                   \

(gdb) x/10i 0xffffffff8048ded8
0xffffffff8048ded8 <tcp_update_scoreboard_fack+528>:    mov    0x8(%rdx),%r12

So if that "CR2: 0000000000000008" is the access address then it appears that
`skb' is NULL.  tcp_write_queue_find() didn't find nuthin.

Re: tcp crash in net-2.6 tree

[Ilpo Järvinen]

On Thu, 29 Mar 2007, Andrew Morton wrote:

> Full -mm lineup.  The x86_64 box was acting as a distcc server at the time.
> 
> Nothing hit the logs, I'm afraid. But almost all the info is in 
> http://userweb.kernel.org/~akpm/s5000494.jpg
>
> <pokes around in gdb a bit>
> 
> It died in tcp_update_scoreboard_fack() here:
> 
>                 if ((!IsFack(tp) || !tcp_skb_timedout(sk, skb)) &&
>                     after(TCP_SKB_CB(skb)->seq, tp->high_seq)) {
>                         /* RFC: should we have find_below? */
>                         skb = tcp_write_queue_find(sk, tp->high_seq);
>                         not_marked_skb = skb;
>                         skb = tcp_write_queue_prev(sk, skb);
>                         /* Timedout top is again uncertain? */
>                         if (tcp_skb_timedout(sk, skb))
>                                 timedout_continue = 1;
>                 }
> 
> 
> (gdb) l *0xffffffff8048ded8
> 0xffffffff8048ded8 is in tcp_update_scoreboard_fack (include/net/tcp.h:1197).
> 1192            return skb->next;
> 1193    }
> 1194    
> 1195    static inline struct sk_buff *tcp_write_queue_prev(struct sock *sk, struct sk_buff *skb)
> 1196    {
> 1197            return skb->prev;
> 1198    }
> 1199    
> 1200    #define tcp_for_write_queue(skb, sk)                                   \
> 
> (gdb) x/10i 0xffffffff8048ded8
> 0xffffffff8048ded8 <tcp_update_scoreboard_fack+528>:    mov    0x8(%rdx),%r12
> 
> So if that "CR2: 0000000000000008" is the access address then it appears that
> `skb' is NULL.  tcp_write_queue_find() didn't find nuthin.

If there is nothing at high_seq (application hasn't given any data to/past 
that point), the search fails to find any skb and returns NULL... But I 
have no idea how this can happen? As TCP does after(skb->seq, 
tp->high_seq) (even in the quoted code block) guaranteeing that something 
is there after the high_seq for TCP to step temporarily on... So at least 
one skb should have it's end_seq after tp->high_seq (actually there 
should be at least two valid skbs after tp->high_seq since the used 
sequence number space does not have holes), which should be enough to get 
an existing skb from write_queue_find?!

I also checked all call paths to tcp_update_scoreboard_fack to make sure 
that snd_una hasn't gone past high_seq and found nothing suspicious (and 
that wouldn't return NULL anyway I think)...


-- 
 i.

Re: tcp crash in net-2.6 tree

[Andrew Morton]

On Fri, 30 Mar 2007 17:33:28 +0300 (EEST) "Ilpo Järvinen" <ilpo.jarvinen@helsinki.fi> wrote:

> On Thu, 29 Mar 2007, Andrew Morton wrote:
> 
> > Full -mm lineup.  The x86_64 box was acting as a distcc server at the time.
> > 
> > Nothing hit the logs, I'm afraid. But almost all the info is in 
> > http://userweb.kernel.org/~akpm/s5000494.jpg
> >
> > <pokes around in gdb a bit>
> > 
> > It died in tcp_update_scoreboard_fack() here:
> > 
> >                 if ((!IsFack(tp) || !tcp_skb_timedout(sk, skb)) &&
> >                     after(TCP_SKB_CB(skb)->seq, tp->high_seq)) {
> >                         /* RFC: should we have find_below? */
> >                         skb = tcp_write_queue_find(sk, tp->high_seq);
> >                         not_marked_skb = skb;
> >                         skb = tcp_write_queue_prev(sk, skb);
> >                         /* Timedout top is again uncertain? */
> >                         if (tcp_skb_timedout(sk, skb))
> >                                 timedout_continue = 1;
> >                 }
> > 
> > 
> > (gdb) l *0xffffffff8048ded8
> > 0xffffffff8048ded8 is in tcp_update_scoreboard_fack (include/net/tcp.h:1197).
> > 1192            return skb->next;
> > 1193    }
> > 1194    
> > 1195    static inline struct sk_buff *tcp_write_queue_prev(struct sock *sk, struct sk_buff *skb)
> > 1196    {
> > 1197            return skb->prev;
> > 1198    }
> > 1199    
> > 1200    #define tcp_for_write_queue(skb, sk)                                   \
> > 
> > (gdb) x/10i 0xffffffff8048ded8
> > 0xffffffff8048ded8 <tcp_update_scoreboard_fack+528>:    mov    0x8(%rdx),%r12
> > 
> > So if that "CR2: 0000000000000008" is the access address then it appears that
> > `skb' is NULL.  tcp_write_queue_find() didn't find nuthin.
> 
> If there is nothing at high_seq (application hasn't given any data to/past 
> that point), the search fails to find any skb and returns NULL... But I 
> have no idea how this can happen? As TCP does after(skb->seq, 
> tp->high_seq) (even in the quoted code block) guaranteeing that something 
> is there after the high_seq for TCP to step temporarily on... So at least 
> one skb should have it's end_seq after tp->high_seq (actually there 
> should be at least two valid skbs after tp->high_seq since the used 
> sequence number space does not have holes), which should be enough to get 
> an existing skb from write_queue_find?!
> 
> I also checked all call paths to tcp_update_scoreboard_fack to make sure 
> that snd_una hasn't gone past high_seq and found nothing suspicious (and 
> that wouldn't return NULL anyway I think)...

Well, could I suggest that you prepare a patch which adds lots of debugging
checks in that area?  I can apply it and will rerun the same workload.

Re: tcp crash in net-2.6 tree

[David Miller]

From: "Ilpo_Järvinen" <ilpo.jarvinen@helsinki.fi>
Date: Fri, 30 Mar 2007 17:33:28 +0300 (EEST)

> If there is nothing at high_seq (application hasn't given any data to/past 
> that point), the search fails to find any skb and returns NULL... But I 
> have no idea how this can happen? As TCP does after(skb->seq, 
> tp->high_seq) (even in the quoted code block) guaranteeing that something 
> is there after the high_seq for TCP to step temporarily on... So at least 
> one skb should have it's end_seq after tp->high_seq (actually there 
> should be at least two valid skbs after tp->high_seq since the used 
> sequence number space does not have holes), which should be enough to get 
> an existing skb from write_queue_find?!
> 
> I also checked all call paths to tcp_update_scoreboard_fack to make sure 
> that snd_una hasn't gone past high_seq and found nothing suspicious (and 
> that wouldn't return NULL anyway I think)...

Let's not speculate, let's find out for sure if snd_una is
surpassing high_seq while we're in this state.

Andrew please give this debugging patch a spin, and also what
is your workload?  I'd like to play with it too.

I've tried to code this patch so that if the bug triggers your
machine shouldn't crash and burn completely, just spit out the
log message.

diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c
index 97b9be2..605b5a8 100644
--- a/net/ipv4/tcp_input.c
+++ b/net/ipv4/tcp_input.c
@@ -1936,14 +1936,32 @@ static void tcp_update_scoreboard_fack(struct sock *sk, u32 entry_seq,
 
 		if ((!IsFack(tp) || !tcp_skb_timedout(sk, skb)) &&
 		    after(TCP_SKB_CB(skb)->seq, tp->high_seq)) {
+			if (after(tp->snd_una, tp->high_seq)) {
+				printk(KERN_ALERT "TCP BUG: snd_una>high_seq "
+				       "[%08x:%08x]\n",
+				       tp->snd_una, tp->high_seq);
+				goto skip;
+			}
 			/* RFC: should we have find_below? */
 			skb = tcp_write_queue_find(sk, tp->high_seq);
+			if (!skb) {
+				struct sk_buff *head = tcp_write_queue_head(sk);
+				struct sk_buff *tail = tcp_write_queue_tail(sk);
+				printk(KERN_ALERT "TCP BUG: high_seq==NULL "
+				       "[%08x] q[%08x] t[%08x]\n",
+				       tp->high_seq,
+				       TCP_SKB_CB(head)->seq,
+				       TCP_SKB_CB(tail)->end_seq);
+				goto skip;
+				       
+			}
 			not_marked_skb = skb;
 			skb = tcp_write_queue_prev(sk, skb);
 			/* Timedout top is again uncertain? */
 			if (tcp_skb_timedout(sk, skb))
 				timedout_continue = 1;
 		}
+skip:
 		/* RFC: ...else if (!tcp_skb_timedout) do skb fragmentation? */
 
 		/* Phase II: Marker */

Re: tcp crash in net-2.6 tree

[Andrew Morton]

On Fri, 30 Mar 2007 14:43:47 -0700 (PDT)
David Miller <davem@davemloft.net> wrote:

> From: "Ilpo_J__rvinen" <ilpo.jarvinen@helsinki.fi>
> Date: Fri, 30 Mar 2007 17:33:28 +0300 (EEST)
> 
> > If there is nothing at high_seq (application hasn't given any data to/past 
> > that point), the search fails to find any skb and returns NULL... But I 
> > have no idea how this can happen? As TCP does after(skb->seq, 
> > tp->high_seq) (even in the quoted code block) guaranteeing that something 
> > is there after the high_seq for TCP to step temporarily on... So at least 
> > one skb should have it's end_seq after tp->high_seq (actually there 
> > should be at least two valid skbs after tp->high_seq since the used 
> > sequence number space does not have holes), which should be enough to get 
> > an existing skb from write_queue_find?!
> > 
> > I also checked all call paths to tcp_update_scoreboard_fack to make sure 
> > that snd_una hasn't gone past high_seq and found nothing suspicious (and 
> > that wouldn't return NULL anyway I think)...
> 
> Let's not speculate, let's find out for sure if snd_una is
> surpassing high_seq while we're in this state.
> 
> Andrew please give this debugging patch a spin,

OK, will take a look at that this evening, hopefully.

> and also what
> is your workload?  I'd like to play with it too.

I use an x86_64 box as a distcc server: shove .i fiels at it, get .o files
sent back.  I was using it thusly and noticed that it had died.

Also, an x86_64 box I have here at google was hanging yesterday and that
appears to have stopped since I removed a couple of x86_64 patches and
git-net.  I'm in the process of working out what fixed it...


> I've tried to code this patch so that if the bug triggers your
> machine shouldn't crash and burn completely, just spit out the
> log message.

ok..  I don't know how repeatable the distcc crash is.  We'll see.

distccd seems to be rather good at triggering networking problems - I think
that's the third one I've seen in the past few years.

Re: tcp crash in net-2.6 tree

[Thomas Graf]

* David Miller <davem@davemloft.net> 2007-03-30 14:43
> Let's not speculate, let's find out for sure if snd_una is
> surpassing high_seq while we're in this state.
> 
> Andrew please give this debugging patch a spin, and also what
> is your workload?  I'd like to play with it too.
> 
> I've tried to code this patch so that if the bug triggers your
> machine shouldn't crash and burn completely, just spit out the
> log message.

I'm running into the same bug as Andew, i was able to reproduce
using Dave's patch within minutes:

TCP BUG: high_seq==NULL [c3c9cc54] q[c3c94edc] t[c3c9cc54]

The after(snd_una, high_seq) check is not triggered.

Re: tcp crash in net-2.6 tree

[David Miller]

From: Andrew Morton <akpm@linux-foundation.org>
Date: Fri, 30 Mar 2007 15:06:03 -0700

> > Andrew please give this debugging patch a spin,
> 
> OK, will take a look at that this evening, hopefully.

BTW, Thomas Graf can also reproduce this and he is about
to post a log message from my patch.

> distccd seems to be rather good at triggering networking problems - I think
> that's the third one I've seen in the past few years.

Agreed, I remember the other hairy problems distcc could trigger.

Re: tcp crash in net-2.6 tree

[David Miller]

From: Thomas Graf <tgraf@suug.ch>
Date: Sat, 31 Mar 2007 00:10:54 +0200

> * David Miller <davem@davemloft.net> 2007-03-30 14:43
> > Let's not speculate, let's find out for sure if snd_una is
> > surpassing high_seq while we're in this state.
> > 
> > Andrew please give this debugging patch a spin, and also what
> > is your workload?  I'd like to play with it too.
> > 
> > I've tried to code this patch so that if the bug triggers your
> > machine shouldn't crash and burn completely, just spit out the
> > log message.
> 
> I'm running into the same bug as Andew, i was able to reproduce
> using Dave's patch within minutes:
> 
> TCP BUG: high_seq==NULL [c3c9cc54] q[c3c94edc] t[c3c9cc54]
> 
> The after(snd_una, high_seq) check is not triggered.

So tp->high_seq points to the tail packet end sequence.

Ilpo does this clear things up?

Re: tcp crash in net-2.6 tree

[ijjarvin]

On 3/31/2007, "David Miller" <davem@davemloft.net> wrote:
> From: Thomas Graf <tgraf@suug.ch>
> Date: Sat, 31 Mar 2007 00:10:54 +0200
> 
> > * David Miller <davem@davemloft.net> 2007-03-30 14:43
> > > Let's not speculate, let's find out for sure if snd_una is
> > > surpassing high_seq while we're in this state.
> > >
> > > Andrew please give this debugging patch a spin, and also what
> > > is your workload?  I'd like to play with it too.
> > >
> > > I've tried to code this patch so that if the bug triggers your
> > > machine shouldn't crash and burn completely, just spit out the
> > > log message.
> >
> > I'm running into the same bug as Andew, i was able to reproduce
> > using Dave's patch within minutes:
> >
> > TCP BUG: high_seq==NULL [c3c9cc54] q[c3c94edc] t[c3c9cc54]
> >
> > The after(snd_una, high_seq) check is not triggered.
> 
> So tp->high_seq points to the tail packet end sequence.
> 
> Ilpo does this clear things up?

Thanks for the info.

I think that the if condition before the write_queue_find should check if
skb is valid before doing after(TCP_SKB_CB(skb)->seq, tp->high_seq), it
is pointing to sk_write_queue rather than a valid skb when the previous
loop exits (there might be a similar problem later in the code too). I
apologize I cannot provide a good patch at this point of time because I
moved on Thursday and the ISP hasn't yet activated the access link
(writing this from a library machine).

--
 i.

Re: tcp crash in net-2.6 tree

[Ilpo Järvinen]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3724 bytes --]

On Sat, 31 Mar 2007, ijjarvin@cs.helsinki.fi wrote:

> On 3/31/2007, "David Miller" <davem@davemloft.net> wrote:
> > From: Thomas Graf <tgraf@suug.ch>
> > Date: Sat, 31 Mar 2007 00:10:54 +0200
> > 
> > > * David Miller <davem@davemloft.net> 2007-03-30 14:43
> > > > Let's not speculate, let's find out for sure if snd_una is
> > > > surpassing high_seq while we're in this state.
> > > >
> > > > Andrew please give this debugging patch a spin, and also what
> > > > is your workload?  I'd like to play with it too.
> > > >
> > > > I've tried to code this patch so that if the bug triggers your
> > > > machine shouldn't crash and burn completely, just spit out the
> > > > log message.
> > >
> > > I'm running into the same bug as Andew, i was able to reproduce
> > > using Dave's patch within minutes:
> > >
> > > TCP BUG: high_seq==NULL [c3c9cc54] q[c3c94edc] t[c3c9cc54]
> > >
> > > The after(snd_una, high_seq) check is not triggered.
> > 
> > So tp->high_seq points to the tail packet end sequence.
> > 
> > Ilpo does this clear things up?
> 
> Thanks for the info.
> 
> I think that the if condition before the write_queue_find should check if
> skb is valid before doing after(TCP_SKB_CB(skb)->seq, tp->high_seq), it
> is pointing to sk_write_queue rather than a valid skb when the previous
> loop exits (there might be a similar problem later in the code too). I
> apologize I cannot provide a good patch at this point of time because I
> moved on Thursday and the ISP hasn't yet activated the access link
> (writing this from a library machine).

So here it is, finally, I'm sorry for the delay (the length of the 
lines this fix is causing does not please me though)...:

[PATCH] [TCP]: Fix invalid skb referencing in LOST marker code

The after() referenced an invalid skb if loop exited when skb had
reached sk_write_queue. I chose to move this part inside the loop
where the skb is valid (so no need to check for that like I first
suggested), which also allows dropping of couple of conditions
from the if.

Signed-off-by: Ilpo Järvinen <ilpo.jarvinen@helsinki.fi>
---
 net/ipv4/tcp_input.c |   25 ++++++++++++-------------
 1 files changed, 12 insertions(+), 13 deletions(-)

diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c
index ea196de..211bb1f 100644
--- a/net/ipv4/tcp_input.c
+++ b/net/ipv4/tcp_input.c
@@ -1933,26 +1933,25 @@ static void tcp_update_scoreboard_fack(s
 				if (IsFack(tp) ||
 				    (TCP_SKB_CB(skb)->sacked & TCPCB_SACKED_ACKED))
 					reord_count += tcp_skb_pcount(skb);
-				if (reord_count > tp->reordering)
+				if (reord_count > tp->reordering) {
+					if (after(TCP_SKB_CB(skb)->seq, tp->high_seq)) {
+						/* RFC: should we have find_below? */
+						skb = tcp_write_queue_find(sk, tp->high_seq);
+						not_marked_skb = skb;
+						skb = tcp_write_queue_prev(sk, skb);
+						/* Timedout top is again uncertain? */
+						if (tcp_skb_timedout(sk, skb))
+							timedout_continue = 1;
+					}
+					/* TODO?: do skb fragmentation if necessary */
 					break;
+				}
 
 				if (!(TCP_SKB_CB(skb)->sacked & TCPCB_SACKED_ACKED))
 					holes_seen += tcp_skb_pcount(skb);
 			}
 		}
 
-		if ((!IsFack(tp) || !tcp_skb_timedout(sk, skb)) &&
-		    after(TCP_SKB_CB(skb)->seq, tp->high_seq)) {
-			/* RFC: should we have find_below? */
-			skb = tcp_write_queue_find(sk, tp->high_seq);
-			not_marked_skb = skb;
-			skb = tcp_write_queue_prev(sk, skb);
-			/* Timedout top is again uncertain? */
-			if (tcp_skb_timedout(sk, skb))
-				timedout_continue = 1;
-		}
-		/* RFC: ...else if (!tcp_skb_timedout) do skb fragmentation? */
-
 		/* Phase II: Marker */
 		tcp_for_write_queue_backwards_from(skb, sk) {
 			if ((tp->fackets_out <= tp->sacked_out + tp->lost_out +
-- 
1.4.2

Re: tcp crash in net-2.6 tree

[David Miller]

From: "Ilpo_Järvinen" <ilpo.jarvinen@helsinki.fi>
Date: Mon, 2 Apr 2007 11:38:51 +0300 (EEST)

> [PATCH] [TCP]: Fix invalid skb referencing in LOST marker code
> 
> The after() referenced an invalid skb if loop exited when skb had
> reached sk_write_queue. I chose to move this part inside the loop
> where the skb is valid (so no need to check for that like I first
> suggested), which also allows dropping of couple of conditions
> from the if.
> 
> Signed-off-by: Ilpo Järvinen <ilpo.jarvinen@helsinki.fi>

Patch applied, thanks a lot Ilpo.

Re: tcp crash in net-2.6 tree

[Thomas Graf]

* David Miller <davem@davemloft.net> 2007-04-02 02:02
> From: "Ilpo_Järvinen" <ilpo.jarvinen@helsinki.fi>
> Date: Mon, 2 Apr 2007 11:38:51 +0300 (EEST)
> 
> > [PATCH] [TCP]: Fix invalid skb referencing in LOST marker code
> > 
> > The after() referenced an invalid skb if loop exited when skb had
> > reached sk_write_queue. I chose to move this part inside the loop
> > where the skb is valid (so no need to check for that like I first
> > suggested), which also allows dropping of couple of conditions
> > from the if.
> > 
> > Signed-off-by: Ilpo Järvinen <ilpo.jarvinen@helsinki.fi>
> 
> Patch applied, thanks a lot Ilpo.

I can no longer trigger the bug, thanks Ilpo.