Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Andrew Morton]

(cc netdev)

(and Rafael - I assume 2.6.24 didn't do this..)

On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:

> (Please CC, not on LKML).
> 
> One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> 
> ------------[ cut here ]------------
> WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
> Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs k8temp hwmon i2c_nforce2 i2c_core sg
> Pid: 32500, comm: php-cgi Not tainted 2.6.25-rc4-git2 #7
> 
> Call Trace:
>  <IRQ>  [<ffffffff80233d2f>] warn_on_slowpath+0x5f/0x80
>  [<ffffffff8057ec9e>] ? __qdisc_run+0xae/0x210
>  [<ffffffff8056f8b6>] ? dev_queue_xmit+0xb6/0x350
>  [<ffffffff805904e0>] ? ip_finish_output+0x0/0x2d0
>  [<ffffffff8059061f>] ? ip_finish_output+0x13f/0x2d0
>  [<ffffffff8059b9a3>] tcp_mark_head_lost+0x173/0x1a0
>  [<ffffffff8059e4f9>] tcp_ack+0x1719/0x2050
>  [<ffffffff805a2188>] tcp_rcv_established+0x438/0x9c0
>  [<ffffffff805c91a5>] ? ip_vs_in+0x215/0x2b0
>  [<ffffffff805a8665>] tcp_v4_do_rcv+0xd5/0x210
>  [<ffffffff80594349>] ? __inet_lookup_established+0xf9/0x1b0
>  [<ffffffff805aa005>] tcp_v4_rcv+0x4a5/0x830
>  [<ffffffff8058c0c5>] ip_local_deliver_finish+0x65/0x1b0
>  [<ffffffff8058c66b>] ip_local_deliver+0x3b/0x90
>  [<ffffffff8058be40>] ip_rcv_finish+0x120/0x340
>  [<ffffffff8058c53a>] ip_rcv+0x1fa/0x2f0
>  [<ffffffff8056c788>] netif_receive_skb+0x2a8/0x330
>  [<ffffffff803ea9f7>] e1000_clean_rx_irq+0x1a7/0x5a0
>  [<ffffffff803e5f2f>] e1000_clean+0x6f/0x290
>  [<ffffffff8056ed99>] net_rx_action+0x109/0x210
>  [<ffffffff80239a04>] __do_softirq+0x74/0xe0
>  [<ffffffff8020c66c>] call_softirq+0x1c/0x30
>  [<ffffffff8020eb5d>] do_softirq+0x3d/0x80
>  [<ffffffff80239985>] irq_exit+0x45/0x50
>  [<ffffffff8020ec55>] do_IRQ+0x85/0x100
>  [<ffffffff8020b9f1>] ret_from_intr+0x0/0xa
>  <EOI> 
> ---[ end trace cd81b9a520cecbe0 ]---
> 
> .config attached.

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Andrew Morton]

On Thu, 3 Apr 2008 21:19:13 -0700 Andrew Morton <akpm@linux-foundation.org> wrote:

> 
> (cc netdev)
> 
> (and Rafael - I assume 2.6.24 didn't do this..)

urgh.

> On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:
> 
> > (Please CC, not on LKML).
> > 
> > One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> > 
> > ------------[ cut here ]------------
> > WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
> > Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs k8temp hwmon i2c_nforce2 i2c_core sg
> > Pid: 32500, comm: php-cgi Not tainted 2.6.25-rc4-git2 #7

I misread that as -rc8.

We fixed a lot of stuff since -rc4.  Please retest current mainline?

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Robin H. Johnson]

[-- Attachment #1: Type: text/plain, Size: 2588 bytes --]

On Thu, Apr 03, 2008 at 09:20:38PM -0700, Andrew Morton wrote:
> On Thu, 3 Apr 2008 21:19:13 -0700 Andrew Morton <akpm@linux-foundation.org> wrote:
> 
> > 
> > (cc netdev)
> > 
> > (and Rafael - I assume 2.6.24 didn't do this..)
> 
> urgh.
> 
> > On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:
> > 
> > > (Please CC, not on LKML).
> > > 
> > > One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> > > 
> > > ------------[ cut here ]------------
> > > WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
> > > Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs k8temp hwmon i2c_nforce2 i2c_core sg
> > > Pid: 32500, comm: php-cgi Not tainted 2.6.25-rc4-git2 #7
> I misread that as -rc8.
> We fixed a lot of stuff since -rc4.  Please retest current mainline?

Hopefully this is new enough. -git3 was released right while I was writing this
email after testing, and I don't see anything in there that seems related.

------------[ cut here ]------------
WARNING: at net/ipv4/tcp_input.c:1771 tcp_enter_frto+0x2bb/0x2c0()
Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs i2c_nforce2 k8temp hwmon i2c_core sg
Pid: 0, comm: swapper Not tainted 2.6.25-rc8-git2 #1

Call Trace:
 <IRQ>  [<ffffffff8023413f>] warn_on_slowpath+0x5f/0x80
 [<ffffffff803ecefb>] ? e1000_alloc_rx_buffers+0xdb/0x3a0
 [<ffffffff803edcc2>] ? e1000_clean_rx_irq+0x312/0x5a0
 [<ffffffff805a44db>] tcp_enter_frto+0x2bb/0x2c0
 [<ffffffff805aa661>] tcp_write_timer+0x3a1/0x790
 [<ffffffff8024c3e5>] ? hrtimer_run_pending+0x35/0xc0
 [<ffffffff805aa2c0>] ? tcp_write_timer+0x0/0x790
 [<ffffffff8023dd5f>] run_timer_softirq+0x18f/0x1f0
 [<ffffffff80239e74>] __do_softirq+0x74/0xf0
 [<ffffffff8020ee9a>] ? profile_pc+0x3a/0x70
 [<ffffffff8020c7cc>] call_softirq+0x1c/0x30
 [<ffffffff8020ecbd>] do_softirq+0x3d/0x80
 [<ffffffff80239df5>] irq_exit+0x45/0x50
 [<ffffffff8021c62e>] smp_apic_timer_interrupt+0x7e/0xc0
 [<ffffffff8020a480>] ? default_idle+0x0/0x70
 [<ffffffff8020c276>] apic_timer_interrupt+0x66/0x70
 <EOI>  [<ffffffff8020a4b9>] ? default_idle+0x39/0x70
 [<ffffffff8020a4b4>] ? default_idle+0x34/0x70
 [<ffffffff8020a480>] ? default_idle+0x0/0x70
 [<ffffffff8020a565>] ? cpu_idle+0x75/0xa0
 [<ffffffff8061deca>] ? rest_init+0x5a/0x60

---[ end trace 52f4c6f608900cab ]---
-- 
Robin Hugh Johnson
Gentoo Linux Developer & Infra Guy
E-Mail     : robbat2@gentoo.org
GnuPG FP   : 11AC BA4F 4778 E3F6 E4ED  F38E B27B 944E 3488 4E85

[-- Attachment #2: Type: application/pgp-signature, Size: 329 bytes --]

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Ilpo Järvinen]

On Fri, 4 Apr 2008, Robin H. Johnson wrote:

> On Thu, Apr 03, 2008 at 09:20:38PM -0700, Andrew Morton wrote:
> > On Thu, 3 Apr 2008 21:19:13 -0700 Andrew Morton <akpm@linux-foundation.org> wrote:
> > 
> > > 
> > > (cc netdev)
> > > 
> > > (and Rafael - I assume 2.6.24 didn't do this..)
> > 
> > urgh.
> > 
> > > On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:
> > > 
> > > > (Please CC, not on LKML).
> > > > 
> > > > One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> > > > 
> > > > ------------[ cut here ]------------
> > > > WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
> > > > Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs k8temp hwmon i2c_nforce2 i2c_core sg
> > > > Pid: 32500, comm: php-cgi Not tainted 2.6.25-rc4-git2 #7
> > I misread that as -rc8.
> > We fixed a lot of stuff since -rc4.  Please retest current mainline?
> 
> Hopefully this is new enough. -git3 was released right while I was writing this
> email after testing, and I don't see anything in there that seems related.
> 
> ------------[ cut here ]------------
> WARNING: at net/ipv4/tcp_input.c:1771 tcp_enter_frto+0x2bb/0x2c0()

Is this _the first one_ you encounter? It's very strange place because
tcp_enter_frto won't touch those sacked_out / lost_out counters at all
so it hardly could cause an overflow there.



-- 
 i.

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Rafael J. Wysocki]

On Friday, 4 of April 2008, Andrew Morton wrote:
> 
> (cc netdev)
> 
> (and Rafael - I assume 2.6.24 didn't do this..)
> 
> On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:

That's http://bugzilla.kernel.org/show_bug.cgi?id=10346 , I think. 

Robin, please add yourself to the CC list in the bugzilla entry above.

> > One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> > 
> > ------------[ cut here ]------------
> > WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
> > Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs k8temp hwmon i2c_nforce2 i2c_core sg
> > Pid: 32500, comm: php-cgi Not tainted 2.6.25-rc4-git2 #7
> > 
> > Call Trace:
> >  <IRQ>  [<ffffffff80233d2f>] warn_on_slowpath+0x5f/0x80
> >  [<ffffffff8057ec9e>] ? __qdisc_run+0xae/0x210
> >  [<ffffffff8056f8b6>] ? dev_queue_xmit+0xb6/0x350
> >  [<ffffffff805904e0>] ? ip_finish_output+0x0/0x2d0
> >  [<ffffffff8059061f>] ? ip_finish_output+0x13f/0x2d0
> >  [<ffffffff8059b9a3>] tcp_mark_head_lost+0x173/0x1a0
> >  [<ffffffff8059e4f9>] tcp_ack+0x1719/0x2050
> >  [<ffffffff805a2188>] tcp_rcv_established+0x438/0x9c0
> >  [<ffffffff805c91a5>] ? ip_vs_in+0x215/0x2b0
> >  [<ffffffff805a8665>] tcp_v4_do_rcv+0xd5/0x210
> >  [<ffffffff80594349>] ? __inet_lookup_established+0xf9/0x1b0
> >  [<ffffffff805aa005>] tcp_v4_rcv+0x4a5/0x830
> >  [<ffffffff8058c0c5>] ip_local_deliver_finish+0x65/0x1b0
> >  [<ffffffff8058c66b>] ip_local_deliver+0x3b/0x90
> >  [<ffffffff8058be40>] ip_rcv_finish+0x120/0x340
> >  [<ffffffff8058c53a>] ip_rcv+0x1fa/0x2f0
> >  [<ffffffff8056c788>] netif_receive_skb+0x2a8/0x330
> >  [<ffffffff803ea9f7>] e1000_clean_rx_irq+0x1a7/0x5a0
> >  [<ffffffff803e5f2f>] e1000_clean+0x6f/0x290
> >  [<ffffffff8056ed99>] net_rx_action+0x109/0x210
> >  [<ffffffff80239a04>] __do_softirq+0x74/0xe0
> >  [<ffffffff8020c66c>] call_softirq+0x1c/0x30
> >  [<ffffffff8020eb5d>] do_softirq+0x3d/0x80
> >  [<ffffffff80239985>] irq_exit+0x45/0x50
> >  [<ffffffff8020ec55>] do_IRQ+0x85/0x100
> >  [<ffffffff8020b9f1>] ret_from_intr+0x0/0xa
> >  <EOI> 
> > ---[ end trace cd81b9a520cecbe0 ]---
> > 
> > .config attached.
> 
> 
> 



-- 
"Premature optimization is the root of all evil." - Donald Knuth

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Georgi Chorbadzhiyski]

Around 04/04/08 12:50, Rafael J. Wysocki scribbled:
> On Friday, 4 of April 2008, Andrew Morton wrote:
>> (cc netdev)
>>
>> (and Rafael - I assume 2.6.24 didn't do this..)
>>
>> On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:
> 
> That's http://bugzilla.kernel.org/show_bug.cgi?id=10346 , I think. 
> 
> Robin, please add yourself to the CC list in the bugzilla entry above.

No idea about 2.6.24 behavior. The kernel I was using before
upgrading to 2.6.25-rc6 was 2.6.21-rc7.

-- 
Georgi Chorbadzhiyski
http://georgi.unixsol.org/

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Ilpo Järvinen]

On Fri, 4 Apr 2008, Rafael J. Wysocki wrote:

> On Friday, 4 of April 2008, Andrew Morton wrote:
> > 
> > (cc netdev)
> > 
> > (and Rafael - I assume 2.6.24 didn't do this..)
> > 
> > On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:
> 
> That's http://bugzilla.kernel.org/show_bug.cgi?id=10346 , I think. 
> 
> Robin, please add yourself to the CC list in the bugzilla entry above.
> 
> > > One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> > > 
> > > ------------[ cut here ]------------
> > > WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

Once Linus pulls net-2.6 fixes in, Robin's bug should be among the fixed 
ones (NewReno&TSO fix). ...Whereas the bugzilla's report might be due to 
another bug (it's different warn_on in any case).

-- 
 i.

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[David Miller]

From: "Ilpo_Järvinen" <ilpo.jarvinen@helsinki.fi>
Date: Fri, 11 Apr 2008 16:05:32 +0300 (EEST)

> On Fri, 4 Apr 2008, Rafael J. Wysocki wrote:
> 
> > That's http://bugzilla.kernel.org/show_bug.cgi?id=10346 , I think. 
> > 
> > Robin, please add yourself to the CC list in the bugzilla entry above.
> > 
> > > > One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> > > > 
> > > > ------------[ cut here ]------------
> > > > WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
> 
> Once Linus pulls net-2.6 fixes in, Robin's bug should be among the fixed 
> ones (NewReno&TSO fix). ...Whereas the bugzilla's report might be due to 
> another bug (it's different warn_on in any case).

Linus has pulled those changes in.

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Tony Lill]

Andrew Morton <akpm@linux-foundation.org> writes:

> (cc netdev)
>
> (and Rafael - I assume 2.6.24 didn't do this..)
>
> On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:
>
>> (Please CC, not on LKML).
>> 
>> One of the nodes in my web-serving cluster (isohunt.com) started showing this:
>> 
>> ------------[ cut here ]------------
>> WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
>> Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs k8temp hwmon i2c_nforce2 i2c_core sg
>> Pid: 32500, comm: php-cgi Not tainted 2.6.25-rc4-git2 #7

Are you talking about the warning in this particular module, or
WARNINGS in tcp_input.c (and tcp_output.c) in general. 'Cause I've
been getting them sporadically since moving from 2.6.23 to 2.6.24.
At least I think that's the timeframe.

Mar 28 23:42:40 matrix kernel: WARNING: at net/ipv4/tcp_output.c:1799 tcp_simple_retransmit()
Mar 29 01:03:32 matrix kernel: WARNING: at net/ipv4/tcp_input.c:2413 tcp_fastretrans_alert()
Mar 29 01:12:41 matrix kernel: WARNING: at net/ipv4/tcp_input.c:1675 tcp_enter_frto()
Mar 29 03:03:04 matrix kernel: WARNING: at net/ipv4/tcp_input.c:2960 tcp_process_frto()
Mar 29 03:03:04 matrix kernel: WARNING: at net/ipv4/tcp_input.c:2314 tcp_try_to_open()

No user visble effects, and no messages since.

-tony

Re: WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()

[Ilpo Järvinen]

On Fri, 4 Apr 2008, Tony Lill wrote:

> Andrew Morton <akpm@linux-foundation.org> writes:
> 
> > (cc netdev)
> >
> > (and Rafael - I assume 2.6.24 didn't do this..)
> >
> > On Wed, 2 Apr 2008 15:41:37 -0700 "Robin H. Johnson" <robbat2@gentoo.org> wrote:
> >
> >> (Please CC, not on LKML).
> >> 
> >> One of the nodes in my web-serving cluster (isohunt.com) started showing this:
> >> 
> >> ------------[ cut here ]------------
> >> WARNING: at net/ipv4/tcp_input.c:2173 tcp_mark_head_lost+0x173/0x1a0()
> >> Modules linked in: lm85 hwmon_vid nfs lockd nfs_acl sunrpc bonding reiserfs k8temp hwmon i2c_nforce2 i2c_core sg
> >> Pid: 32500, comm: php-cgi Not tainted 2.6.25-rc4-git2 #7
> 
> Are you talking about the warning in this particular module, or
> WARNINGS in tcp_input.c (and tcp_output.c) in general. 'Cause I've
> been getting them sporadically since moving from 2.6.23 to 2.6.24.

2.6.22-2.6.23 did have WARNINGs but BUG_ON but I had to back off from that 
for NewReno case because it was just hitting it because of some 
transitional states (SACK TCP has been under this check since 2.6.22, 
before that it just silently corrected incorrect estimates). For 2.6.24 
the severity was reduced to WARN_ON to avoid crashing people boxes and 
NewReno case was added to the check.

> At least I think that's the timeframe.
> 
> Mar 28 23:42:40 matrix kernel: WARNING: at net/ipv4/tcp_output.c:1799 tcp_simple_retransmit()
> Mar 29 01:03:32 matrix kernel: WARNING: at net/ipv4/tcp_input.c:2413 tcp_fastretrans_alert()
> Mar 29 01:12:41 matrix kernel: WARNING: at net/ipv4/tcp_input.c:1675 tcp_enter_frto()
> Mar 29 03:03:04 matrix kernel: WARNING: at net/ipv4/tcp_input.c:2960 tcp_process_frto()
> Mar 29 03:03:04 matrix kernel: WARNING: at net/ipv4/tcp_input.c:2314 tcp_try_to_open()
> 
> No user visble effects, and no messages since.

In general they're rather harmless (and that combined with the rareness 
of it makes people to not very easily report them), a packet burst in the 
worst case which nobody usually is able to see (if packets_in_flight ends 
up underflowing). Would I not have enabled the tracking, the bugs causing 
them now to show up would never have been detected nor fixed (e.g., the 
tcp_simple_retransmit bug I found yesterday is a long standing one rather 
than regression, also there have been couple of other long standing ones 
found earlier which are nowadays fixed).

-- 
 i.