Oops in tcp_sendmsg on T1000

Oops in tcp_sendmsg on T1000

[Rene Rebe]

Hi all,

I just test the freshly installed T1000 under load and got a single stray oops
after 5 hours of uptime with excessive load (software compilation). The
software is the T2 release from this week (software compiled from
vanilla sources) with GCC 4.1.1, Kernel 2.6.17.2:

Linux version 2.6.17.2-dist (root@localhost) (gcc version 4.1.1) #1 SMP Fri Jun 30 14:30:38 /TOOLCHAIN/localtime 2006

The same kernel binary runs on Ultra30 and Ultra5 since days without any
problem, however I already can imagine that David will slap me for using
GCC 4.1.1. Maybe someone is interested anyway:

kernel BUG at include/linux/skbuff.h:457!
              \|/ ____ \|/
              "@'/ .. \`@"
              /_| \__/ |_\
                 \__U_/
sshd(21849): Kernel bad sw trap 5 [#1]
TSTATE: 0000000011001601 TPC: 00000000005c5c2c TNPC: 00000000005c5c30 Y: 00000000    Not tainted
TPC: <tcp_sendmsg+0x3b0/0xcb0>
g0: 0000000000000830 g1: 0000000000656400 g2: 0000000000714400 g3: 0000000000002bb9
g4: fffff8018cde7060 g5: fffff80003d660c0 g6: fffff8016f6f0000 g7: 0000000000000000
o0: 000000000000002d o1: 0000000000621e30 o2: 00000000000001c9 o3: 0000000000000240
o4: 00000000ff1e8eef o5: 0000000000000240 sp: fffff8016f6f2fb1 ret_pc: 00000000005c5c24
RPC: <tcp_sendmsg+0x3a8/0xcb0>
l0: fffff801248057a0 l1: 0000000000000100 l2: 000000000041220c l3: 000000000008ad78
l4: 0000000000000010 l5: 000000000000000b l6: fffff8016f6f0000 l7: 00000000000cc950
i0: 0000000000004000 i1: fffff8017f4b2780 i2: 0000000000000000 i3: 0000000000000040
i4: 0000000000004000 i5: 0000000000000240 i6: fffff8016f6f30a1 i7: 00000000005e1928
I7: <inet_sendmsg+0x44/0x58>
Caller[00000000005e1928]: inet_sendmsg+0x44/0x58
Caller[000000000059019c]: do_sock_write+0xa0/0xb4
Caller[0000000000590960]: sock_aio_write+0x48/0x5c
Caller[000000000048e3a0]: do_sync_write+0x80/0xc0
Caller[000000000048ec5c]: vfs_write+0x88/0x120
Caller[000000000048f12c]: sys_write+0x2c/0x60
Caller[0000000000406c94]: linux_sparc_syscall32+0x34/0x40
Caller[000000000003473c]: 0x3473c
Instruction DUMP: 90122230  7ff95253  01000000 <91d02005> 84050012  c4242088  8204c001  80a04003  08680007

-- 
René Rebe - ExactCODE - Berlin (Europe / Germany)
            http://exactcode.de | http://t2-project.org | http://rene.rebe.name
            +49 (0)30 / 255 897 45

Re: Oops in tcp_sendmsg on T1000

[David Miller]

From: Rene Rebe <rene@exactcode.de>
Date: Sat, 1 Jul 2006 14:21:56 +0200

> after 5 hours of uptime with excessive load (software compilation). The
> software is the T2 release from this week (software compiled from
> vanilla sources) with GCC 4.1.1, Kernel 2.6.17.2:

If you can reproduce this with gcc-4.0.x I'd really appreciate
it.

Re: Oops in tcp_sendmsg on T1000

[Rene Rebe]

Hi,

On Sunday 02 July 2006 00:19, David Miller wrote:
> From: Rene Rebe <rene@exactcode.de>
> Date: Sat, 1 Jul 2006 14:21:56 +0200
>
> > after 5 hours of uptime with excessive load (software compilation). The
> > software is the T2 release from this week (software compiled from
> > vanilla sources) with GCC 4.1.1, Kernel 2.6.17.2:
>
> If you can reproduce this with gcc-4.0.x I'd really appreciate
> it.

I feared that. It will not be easy to reproduce it since it only happend once,
yesterday, and the machine continued to run fine (despite the oops) for
serveral more hours under high load so far.

Is there any chance the post 2.6.17 sparc64 and tg3 changes make a
difference or should I rather really try hard to reprouce it with the
2.6.17.2 kernel to find the real culprit?

Yours,

-- 
René Rebe - Rubensstr. 64 - 12157 Berlin (Europe / Germany)
            http://exactcode.de | http://t2-project.org | http://rebe.name
            +49 (0)30 / 255 897 45

Re: Oops in tcp_sendmsg on T1000

[David Miller]

From: Rene Rebe <rene@exactcode.de>
Date: Sun, 2 Jul 2006 17:14:19 +0200

> Is there any chance the post 2.6.17 sparc64 and tg3 changes make a
> difference or should I rather really try hard to reprouce it with the
> 2.6.17.2 kernel to find the real culprit?

2.6.17.x should be extremely stable and there is nothing
in the current tree that ought to fix this.

Please retry with gcc-4.0.x, I really want to eliminate
gcc-4.1.x because that compiler has caused problems for
other folks.  In fact I'm almost hoping it's a gcc-4.1.x
problem so we can investigate it using this test case and
fix it :)

Re: Oops in tcp_sendmsg on T1000

[Rene Rebe]

On Sunday 02 July 2006 18:32, David Miller wrote:
> From: Rene Rebe <rene@exactcode.de>
> Date: Sun, 2 Jul 2006 17:14:19 +0200
>
> > Is there any chance the post 2.6.17 sparc64 and tg3 changes make a
> > difference or should I rather really try hard to reprouce it with the
> > 2.6.17.2 kernel to find the real culprit?
>
> 2.6.17.x should be extremely stable and there is nothing
> in the current tree that ought to fix this.
>
> Please retry with gcc-4.0.x, I really want to eliminate
> gcc-4.1.x because that compiler has caused problems for
> other folks.  In fact I'm almost hoping it's a gcc-4.1.x
> problem so we can investigate it using this test case and
> fix it :)

Understood. However so far it did not reoccur, still testing
the box under continous high load :-(

Best regards,

-- 
René Rebe - Rubensstr. 64 - 12157 Berlin (Europe / Germany)
            http://exactcode.de | http://t2-project.org | http://rebe.name
            +49 (0)30 / 255 897 45

Re: Oops in tcp_sendmsg on T1000

[Jurij Smakov]

On Sun, 2 Jul 2006, David Miller wrote:

> 2.6.17.x should be extremely stable and there is nothing
> in the current tree that ought to fix this.
>
> Please retry with gcc-4.0.x, I really want to eliminate
> gcc-4.1.x because that compiler has caused problems for
> other folks.  In fact I'm almost hoping it's a gcc-4.1.x
> problem so we can investigate it using this test case and
> fix it :)

FWIW, I have experienced exactly the opposite while preparing the 2.6.17 
for Debian: the SMP kernel built with gcc-4.0 was hanging randomly 
during boot, but works fine when built with gcc-4.1.

Best regards,

Jurij Smakov                                        jurij@wooyd.org
Key: http://www.wooyd.org/pgpkey/                   KeyID: C99E03CC

Re: Oops in tcp_sendmsg on T1000

[Dennis Gilmore]

On Saturday 01 July 2006 7:21 am, Rene Rebe wrote:
> Hi all,
>
> I just test the freshly installed T1000 under load and got a single stray
> oops after 5 hours of uptime with excessive load (software compilation).
> The software is the T2 release from this week (software compiled from
> vanilla sources) with GCC 4.1.1, Kernel 2.6.17.2:
>
> Linux version 2.6.17.2-dist (root@localhost) (gcc version 4.1.1) #1 SMP Fri
> Jun 30 14:30:38 /TOOLCHAIN/localtime 2006
>
> The same kernel binary runs on Ultra30 and Ultra5 since days without any
> problem, however I already can imagine that David will slap me for using
> GCC 4.1.1. Maybe someone is interested anyway:

I am using a 2.6.17pre  kernel  on my T1000 
Linux version 2.6.16-1.2241sp7 (root@arthur.devel.redhat.com) (gcc version 
3.4.2 20041017 (Red Hat 3.4.2-6.fc3)) #1 SMP Thu Jun 29 10:59:22 EDT 2006

i have been using it with an average load of around 10 for a couple of days 
now.  It has received 125gb in that time.  and have not seen any issues at 
all.



-- 
Dennis Gilmore, RHCE
Proud Australian

Re: Oops in tcp_sendmsg on T1000

[Ben Collins]

On Sun, 2006-07-02 at 12:13 -0700, Jurij Smakov wrote:
> On Sun, 2 Jul 2006, David Miller wrote:
> 
> > 2.6.17.x should be extremely stable and there is nothing
> > in the current tree that ought to fix this.
> >
> > Please retry with gcc-4.0.x, I really want to eliminate
> > gcc-4.1.x because that compiler has caused problems for
> > other folks.  In fact I'm almost hoping it's a gcc-4.1.x
> > problem so we can investigate it using this test case and
> > fix it :)
> 
> FWIW, I have experienced exactly the opposite while preparing the 2.6.17 
> for Debian: the SMP kernel built with gcc-4.0 was hanging randomly 
> during boot, but works fine when built with gcc-4.1.

Was this an SMP machine/kernel? If so, it sounds like the scheduler
tuning bug, fixed in the latest kernel (maybe dave knows git sha).

-- 
Ubuntu     - http://www.ubuntu.com/
Debian     - http://www.debian.org/
Linux 1394 - http://www.linux1394.org/
SwissDisk  - http://www.swissdisk.com/

Re: Oops in tcp_sendmsg on T1000

[Dennis Gilmore]

On Sunday 02 July 2006 19:02, Dennis Gilmore wrote:
> On Saturday 01 July 2006 7:21 am, Rene Rebe wrote:
> > Hi all,
> >
> > I just test the freshly installed T1000 under load and got a single stray
> > oops after 5 hours of uptime with excessive load (software compilation).
> > The software is the T2 release from this week (software compiled from
> > vanilla sources) with GCC 4.1.1, Kernel 2.6.17.2:
> >
>
> I am using a 2.6.17pre  kernel  on my T1000
> Linux version 2.6.16-1.2241sp7 (root@arthur.devel.redhat.com) (gcc version
> 3.4.2 20041017 (Red Hat 3.4.2-6.fc3)) #1 SMP Thu Jun 29 10:59:22 EDT 2006
>
> i have been using it with an average load of around 10 for a couple of days
> now.  It has received 125gb in that time.  and have not seen any issues at
> all.
I spoke too soon  just got an oops  the nfs connection locked up with the oops

kernel BUG at include/linux/skbuff.h:466!
              \|/ ____ \|/
              "@'/ .. \`@"
              /_| \__/ |_\
                 \__U_/
rpciod/2(2109): Kernel bad sw trap 5 [#1]
TSTATE: 0000000080001602 TPC: 0000000000630534 TNPC: 0000000000630538 Y: 
00000000    Not tainted
TPC: <tcp_sendmsg+0x5ec/0xc7c>
g0: fffff803fb1b2b98 g1: 00000000006d0c00 g2: ffffffffffffffd3 g3: 
00000000007a3400
g4: fffff803fb7905a0 g5: fffff800074fa0c0 g6: fffff803fa868000 g7: 
0000000000000000
o0: 000000000000002d o1: 000000000068ae68 o2: 00000000000001d2 o3: 
000000000000009c
o4: 000000000000009c o5: 0000000000000080 sp: fffff803fa86abd1 ret_pc: 
000000000063052c
RPC: <tcp_sendmsg+0x5e4/0xc7c>
l0: fffff80169cce580 l1: fffff80169cce580 l2: 0000000000000000 l3: 
fffff803fa86b930
l4: fffff803fb1b2b98 l5: 0000000000000000 l6: fffff803fd909aa0 l7: 
fffff803fb1b2b90
i0: ffffffffffffffe0 i1: fffff8008ad23780 i2: 0000000000000000 i3: 
0000000000004040
i4: 000000000000009c i5: fffff801bc71a000 i6: fffff803fa86acd1 i7: 
000000000064e834
I7: <inet_sendmsg+0x40/0x54>
Caller[000000000064e834]: inet_sendmsg+0x40/0x54
Caller[00000000005f8110]: sock_sendmsg+0xac/0xd8
Caller[00000000005f8160]: kernel_sendmsg+0x24/0x40
Caller[00000000100e7d78]: xs_tcp_send_request+0x108/0x360 [sunrpc]
Caller[00000000100e6cf0]: xprt_transmit+0xec/0x228 [sunrpc]
Caller[00000000100e55f0]: call_transmit+0x1e0/0x230 [sunrpc]
Caller[00000000100eaa34]: __rpc_execute+0xa4/0x244 [sunrpc]
Caller[0000000000460974]: run_workqueue+0xb8/0x10c
Caller[0000000000460aa8]: worker_thread+0xe0/0x11c
Caller[0000000000464498]: kthread+0xb4/0xe8
Caller[00000000004187a0]: kernel_thread+0x30/0x48
Caller[00000000004644dc]: keventd_create_kthread+0x10/0x88
Instruction DUMP: 90122048  7ff7a1de  01000000 <91d02005> 15001b50  82102049  
83287008  9412a180  94028001

Re: Oops in tcp_sendmsg on T1000

[David Miller]

From: Ben Collins <bcollins@ubuntu.com>
Date: Mon, 03 Jul 2006 12:16:15 -0400

> Was this an SMP machine/kernel? If so, it sounds like the scheduler
> tuning bug, fixed in the latest kernel (maybe dave knows git sha).

It is on a T1000, SMP is a given :)

Re: Oops in tcp_sendmsg on T1000

[Jurij Smakov]

On Mon, 3 Jul 2006, David Miller wrote:

> From: Ben Collins <bcollins@ubuntu.com>
> Date: Mon, 03 Jul 2006 12:16:15 -0400
>
>> Was this an SMP machine/kernel? If so, it sounds like the scheduler
>> tuning bug, fixed in the latest kernel (maybe dave knows git sha).
>
> It is on a T1000, SMP is a given :)

I have to apologize for not making it sufficiently clear (and for not 
starting a different thread, for that matter), but I was talking about my 
experiences with a 2-CPU Ultra60. So, the accurate statement is: a 2.6.17 
kernel built with gcc-4.0 failed to boot on it, while gcc-4.1 worked fine.

Once again, sorry for confusion.

Jurij Smakov                                        jurij@wooyd.org
Key: http://www.wooyd.org/pgpkey/                   KeyID: C99E03CC

Re: Oops in tcp_sendmsg on T1000

[David Miller]

From: Rene Rebe <rene@exactcode.de>
Date: Sat, 1 Jul 2006 14:21:56 +0200

> kernel BUG at include/linux/skbuff.h:457!
>               \|/ ____ \|/
>               "@'/ .. \`@"
>               /_| \__/ |_\
>                  \__U_/
> sshd(21849): Kernel bad sw trap 5 [#1]
> TSTATE: 0000000011001601 TPC: 00000000005c5c2c TNPC: 00000000005c5c30 Y: 00000000    Not tainted
> TPC: <tcp_sendmsg+0x3b0/0xcb0>
> g0: 0000000000000830 g1: 0000000000656400 g2: 0000000000714400 g3: 0000000000002bb9
> g4: fffff8018cde7060 g5: fffff80003d660c0 g6: fffff8016f6f0000 g7: 0000000000000000
> o0: 000000000000002d o1: 0000000000621e30 o2: 00000000000001c9 o3: 0000000000000240
> o4: 00000000ff1e8eef o5: 0000000000000240 sp: fffff8016f6f2fb1 ret_pc: 00000000005c5c24
> RPC: <tcp_sendmsg+0x3a8/0xcb0>

Let's try to get some more debugging.  It looks like an SKB is being
referenced after it has been freed up, or something like this.

Please add this patch and report what it prints, thanks a lot.

diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
index f6a2d92..a3cb2cf 100644
--- a/net/ipv4/tcp.c
+++ b/net/ipv4/tcp.c
@@ -467,6 +467,10 @@ static inline void skb_entail(struct soc
 	TCP_SKB_CB(skb)->end_seq = tp->write_seq;
 	TCP_SKB_CB(skb)->flags = TCPCB_FLAG_ACK;
 	TCP_SKB_CB(skb)->sacked = 0;
+	if (skb->nohdr) {
+		printk("TCP DEBUG: Bogus skb->nohdr, word[%08x]\n",
+		       *(&skb->priority + 1));
+	}
 	skb_header_release(skb);
 	__skb_queue_tail(&sk->sk_write_queue, skb);
 	sk_charge_skb(sk, skb);

Re: Oops in tcp_sendmsg on T1000

[Rene Rebe]

Hi,

On Saturday 08 July 2006 03:21, David Miller wrote:
> From: Rene Rebe <rene@exactcode.de>
> Date: Sat, 1 Jul 2006 14:21:56 +0200
>
> > kernel BUG at include/linux/skbuff.h:457!
> >               \|/ ____ \|/
> >               "@'/ .. \`@"
> >               /_| \__/ |_\
> >                  \__U_/
> > sshd(21849): Kernel bad sw trap 5 [#1]
> > TSTATE: 0000000011001601 TPC: 00000000005c5c2c TNPC: 00000000005c5c30 Y:
> > 00000000    Not tainted TPC: <tcp_sendmsg+0x3b0/0xcb0>
> > g0: 0000000000000830 g1: 0000000000656400 g2: 0000000000714400 g3:
> > 0000000000002bb9 g4: fffff8018cde7060 g5: fffff80003d660c0 g6:
> > fffff8016f6f0000 g7: 0000000000000000 o0: 000000000000002d o1:
> > 0000000000621e30 o2: 00000000000001c9 o3: 0000000000000240 o4:
> > 00000000ff1e8eef o5: 0000000000000240 sp: fffff8016f6f2fb1 ret_pc:
> > 00000000005c5c24 RPC: <tcp_sendmsg+0x3a8/0xcb0>
>
> Let's try to get some more debugging.  It looks like an SKB is being
> referenced after it has been freed up, or something like this.
>
> Please add this patch and report what it prints, thanks a lot.
>
> diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
> index f6a2d92..a3cb2cf 100644
> --- a/net/ipv4/tcp.c
> +++ b/net/ipv4/tcp.c
> @@ -467,6 +467,10 @@ static inline void skb_entail(struct soc
>  	TCP_SKB_CB(skb)->end_seq = tp->write_seq;
>  	TCP_SKB_CB(skb)->flags = TCPCB_FLAG_ACK;
>  	TCP_SKB_CB(skb)->sacked = 0;
> +	if (skb->nohdr) {
> +		printk("TCP DEBUG: Bogus skb->nohdr, word[%08x]\n",
> +		       *(&skb->priority + 1));
> +	}
>  	skb_header_release(skb);
>  	__skb_queue_tail(&sk->sk_write_queue, skb);
>  	sk_charge_skb(sk, skb);

I run a 2.6.17.4 kernel with the above patch on the T1000, now.
But since I got the Oops only once so far it might take some days++
to reappear ...

-- 
René Rebe - Rubensstr. 64 - 12157 Berlin (Europe / Germany)
            http://exactcode.de | http://t2-project.org | http://rebe.name
            +49 (0)30 / 255 897 45

Re: Oops in tcp_sendmsg on T1000

[David Miller]

From: Rene Rebe <rene@exactcode.de>
Date: Sat, 8 Jul 2006 20:57:05 +0200

> I run a 2.6.17.4 kernel with the above patch on the T1000, now.
> But since I got the Oops only once so far it might take some days++
> to reappear ...

Ok, let me know when it triggers :)