2.6.25.6: warn_on_slowpath in tcp_input.c - Kernel

This is a discussion on 2.6.25.6: warn_on_slowpath in tcp_input.c - Kernel ; Hey, I found a couple of backtraces on one of our machines. I didn't notice anything weird on it other than that; it seems to be pushing its constant 40 to 60 Mbps as always. I've had 13 or so ...

+ Reply to Thread
Results 1 to 5 of 5

Thread: 2.6.25.6: warn_on_slowpath in tcp_input.c

  1. 2.6.25.6: warn_on_slowpath in tcp_input.c

    Hey,

    I found a couple of backtraces on one of our machines. I didn't notice
    anything weird on it other than that; it seems to be pushing its
    constant 40 to 60 Mbps as always.

    I've had 13 or so of them since upgrading the machine to a 2.6.25 kernel
    20 days ago.

    Linux saens 2.6.25.6-dl380 #2 SMP Tue Jun 10 17:54:44 CEST 2008 i686 GNU/Linux


    Jun 30 04:08:50 saens kernel: [1659894.570682] ------------[ cut here ]------------
    Jun 30 04:08:50 saens kernel: [1659894.570682] WARNING: at net/ipv4/tcp_input.c:2539 tcp_ack+0x1b35/0x1d72()
    Jun 30 04:08:50 saens kernel: [1659894.570682] Pid: 0, comm: swapper Not tainted 2.6.25.6-dl380 #2
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] warn_on_slowpath+0x49/0x59
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? __free_pages+0x27/0x29
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? free_pages+0x1f/0x21
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? kmem_freepages+0x90/0xc4
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? slab_destroy+0x2f/0x47
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? free_block+0x119/0x12e
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? memmove+0x28/0x2f
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? cache_flusharray+0x78/0xb8
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? bictcp_cong_avoid+0x13/0x383
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? skb_release_data+0x59/0x85
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] tcp_ack+0x1b35/0x1d72
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? tcp_v4_send_synack+0x9d/0xf2
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] tcp_rcv_established+0x41d/0x8c7
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? tcp_error+0xaa/0x1c0
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? tcp_error+0x0/0x1c0
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] tcp_v4_do_rcv+0x3cb/0x50a
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? __inet_lookup_established+0xc7/0x179
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] tcp_v4_rcv+0x573/0x777
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ip_local_deliver_finish+0x7b/0x1af
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ip_local_deliver+0x2d/0x96
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? ip_local_deliver_finish+0x0/0x1af
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ip_rcv_finish+0xc7/0x293
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? nf_hook_slow+0x4a/0xb5
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? ip_rcv_finish+0x0/0x293
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ip_rcv+0x197/0x271
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? ip_rcv_finish+0x0/0x293
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] netif_receive_skb+0x220/0x2ac
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] e100_poll+0x140/0x45d
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? hrtimer_start+0xb4/0x137
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] net_rx_action+0x89/0x16d
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] __do_softirq+0x75/0xe6
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] do_softirq+0x3b/0x3d
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] irq_exit+0x63/0x75
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] do_IRQ+0x45/0x7a
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] common_interrupt+0x23/0x28
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? sys_setregid+0xa/0x107
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? default_idle+0x40/0x5f
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] ? default_idle+0x0/0x5f
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] cpu_idle+0x4f/0x8d
    Jun 30 04:08:50 saens kernel: [1659894.570682] [] rest_init+0x49/0x4b
    Jun 30 04:08:50 saens kernel: [1659894.570682] =======================
    Jun 30 04:08:50 saens kernel: [1659894.570682] ---[ end trace 2b6550de0a1db34c ]---

    Most are very similar, differences being these:

    --- 1a 2008-07-01 00:54:56.514224160 +0200
    +++ 2 2008-07-01 00:55:03.410219826 +0200
    @@ -8,11 +8,12 @@
    [] ? slab_destroy+0x2f/0x47
    [] ? free_block+0x119/0x12e
    [] ? memmove+0x28/0x2f
    + [] ? memmove+0x28/0x2f
    [] ? cache_flusharray+0x78/0xb8
    - [] ? bictcp_cong_avoid+0x13/0x383
    [] ? skb_release_data+0x59/0x85
    + [] ? tcp_enter_frto_loss+0x163/0x1d3
    [] tcp_ack+0x1b35/0x1d72
    - [] ? tcp_v4_send_synack+0x9d/0xf2
    + [] ? lock_timer_base+0x1f/0x40
    [] tcp_rcv_established+0x41d/0x8c7
    [] ? tcp_error+0xaa/0x1c0
    [] ? tcp_error+0x0/0x1c0

    or
    --- 1a 2008-07-01 00:54:56.514224160 +0200
    +++ 3 2008-07-01 00:55:35.554219380 +0200
    @@ -8,11 +8,10 @@
    [] ? slab_destroy+0x2f/0x47
    [] ? free_block+0x119/0x12e
    [] ? memmove+0x28/0x2f
    + [] ? memmove+0x28/0x2f
    [] ? cache_flusharray+0x78/0xb8
    - [] ? bictcp_cong_avoid+0x13/0x383
    - [] ? skb_release_data+0x59/0x85
    + [] ? tcp_enter_frto_loss+0x163/0x1d3
    [] tcp_ack+0x1b35/0x1d72
    - [] ? tcp_v4_send_synack+0x9d/0xf2
    [] tcp_rcv_established+0x41d/0x8c7
    [] ? tcp_error+0xaa/0x1c0
    [] ? tcp_error+0x0/0x1c0



    This one is different since it doesn't come via __free_pages but from
    ip_finish_output:

    ------------[ cut here ]------------
    WARNING: at net/ipv4/tcp_input.c:2539 tcp_ack+0x1b35/0x1d72()
    Pid: 0, comm: swapper Not tainted 2.6.25.6-dl380 #2
    [] warn_on_slowpath+0x49/0x59
    [] ? ip_finish_output+0x0/0x281
    [] ? ip_output+0x5c/0x95
    [] ? ip_finish_output+0x0/0x281
    [] ? ip_local_out+0x18/0x1b
    [] ? memmove+0x28/0x2f
    [] ? cache_flusharray+0x78/0xb8
    [] ? skb_release_data+0x59/0x85
    [] ? tcp_enter_frto_loss+0x163/0x1d3
    [] tcp_ack+0x1b35/0x1d72
    [] ? _spin_unlock_bh+0xd/0xf
    [] ? tcp_packet+0x496/0xb3d
    [] tcp_rcv_state_process+0x40d/0xa7f
    [] ? _read_unlock_bh+0xe/0x10
    [] tcp_v4_do_rcv+0x11c/0x50a
    [] ? __inet_lookup_established+0xc7/0x179
    [] tcp_v4_rcv+0x573/0x777
    [] ip_local_deliver_finish+0x7b/0x1af
    [] ip_local_deliver+0x2d/0x96
    [] ? ip_local_deliver_finish+0x0/0x1af
    [] ip_rcv_finish+0xc7/0x293
    [] ? nf_hook_slow+0x4a/0xb5
    [] ? ip_rcv_finish+0x0/0x293
    [] ip_rcv+0x197/0x271
    [] ? ip_rcv_finish+0x0/0x293
    [] netif_receive_skb+0x220/0x2ac
    [] e100_poll+0x140/0x45d
    [] ? hrtimer_start+0xb4/0x137
    [] net_rx_action+0x89/0x16d
    [] __do_softirq+0x75/0xe6
    [] do_softirq+0x3b/0x3d
    [] irq_exit+0x63/0x75
    [] do_IRQ+0x45/0x7a
    [] ? irq_exit+0x55/0x75
    [] ? smp_apic_timer_interrupt+0x5d/0x8b
    [] common_interrupt+0x23/0x28
    [] ? sys_setregid+0xa/0x107
    [] ? default_idle+0x40/0x5f
    [] ? default_idle+0x0/0x5f
    [] cpu_idle+0x4f/0x8d
    [] rest_init+0x49/0x4b
    =======================
    ---[ end trace 2b6550de0a1db34c ]---

    another variation of that is

    ------------[ cut here ]------------
    WARNING: at net/ipv4/tcp_input.c:2539 tcp_ack+0x1b35/0x1d72()
    Pid: 0, comm: swapper Not tainted 2.6.25.6-dl380 #2
    [] warn_on_slowpath+0x49/0x59
    [] ? ip_finish_output+0x135/0x281
    [] ? ip_finish_output+0x0/0x281
    [] ? memmove+0x28/0x2f
    [] ? cache_flusharray+0x78/0xb8
    [] ? lock_timer_base+0x1f/0x40
    [] ? tcp_snd_test+0x15/0xea
    [] ? tcp_may_send_now+0x40/0x59
    [] tcp_ack+0x1b35/0x1d72
    [] tcp_rcv_established+0x41d/0x8c7
    [] ? tcp_error+0xaa/0x1c0
    [] ? tcp_error+0x0/0x1c0
    [] tcp_v4_do_rcv+0x3cb/0x50a
    [] ? __inet_lookup_established+0xc7/0x179
    [] tcp_v4_rcv+0x573/0x777
    [] ip_local_deliver_finish+0x7b/0x1af
    [] ip_local_deliver+0x2d/0x96
    [] ? ip_local_deliver_finish+0x0/0x1af
    [] ip_rcv_finish+0xc7/0x293
    [] ? nf_hook_slow+0x4a/0xb5
    [] ? ip_rcv_finish+0x0/0x293
    [] ip_rcv+0x197/0x271
    [] ? ip_rcv_finish+0x0/0x293
    [] netif_receive_skb+0x220/0x2ac
    [] e100_poll+0x140/0x45d
    [] ? clockevents_program_event+0xae/0x104
    [] net_rx_action+0x89/0x16d
    [] __do_softirq+0x75/0xe6
    [] do_softirq+0x3b/0x3d
    [] irq_exit+0x63/0x75
    [] do_IRQ+0x45/0x7a
    [] common_interrupt+0x23/0x28
    [] ? sys_setregid+0xa/0x107
    [] ? default_idle+0x40/0x5f
    [] ? default_idle+0x0/0x5f
    [] cpu_idle+0x4f/0x8d
    [] rest_init+0x49/0x4b
    =======================
    ---[ end trace 2b6550de0a1db34c ]---



    If you need to know anything else please let me know. Please CC me on
    replies,

    Peter
    --
    | .''`. ** Debian GNU/Linux **
    Peter Palfrader | : :' : The universal
    http://www.palfrader.org/ | `. `' Operating System
    | `- http://www.debian.org/
    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

  2. Re: 2.6.25.6: warn_on_slowpath in tcp_input.c

    On Mon, Jun 30, 2008 at 4:09 PM, Peter Palfrader wrote:
    > I've had 13 or so of them since upgrading the machine to a 2.6.25 kernel
    > 20 days ago.


    Which kernel was it running before?

    AGL

    --
    Adam Langley agl@imperialviolet.org http://www.imperialviolet.org
    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

  3. Re: 2.6.25.6: warn_on_slowpath in tcp_input.c

    On Mon, 30 Jun 2008, Adam Langley wrote:

    > On Mon, Jun 30, 2008 at 4:09 PM, Peter Palfrader wrote:
    > > I've had 13 or so of them since upgrading the machine to a 2.6.25 kernel
    > > 20 days ago.

    >
    > Which kernel was it running before?


    It was running 2.6.22.17 (+ the splice fix) before that.

    --
    | .''`. ** Debian GNU/Linux **
    Peter Palfrader | : :' : The universal
    http://www.palfrader.org/ | `. `' Operating System
    | `- http://www.debian.org/
    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

  4. Re: 2.6.25.6: warn_on_slowpath in tcp_input.c

    On Tue, 1 Jul 2008, Peter Palfrader wrote:

    > On Mon, 30 Jun 2008, Adam Langley wrote:
    >
    > > On Mon, Jun 30, 2008 at 4:09 PM, Peter Palfrader wrote:
    > > > I've had 13 or so of them since upgrading the machine to a 2.6.25 kernel
    > > > 20 days ago.
    > > >
    > > > Linux saens 2.6.25.6-dl380 #2 SMP Tue Jun 10 17:54:44 CEST 2008 i686 GNU/Linux

    > >
    > > Which kernel was it running before?

    >
    > It was running 2.6.22.17 (+ the splice fix) before that.


    Thanks for the report, I've been away for a while, thus the late response.
    Please update to get this relevant fix and some other TCP fixes (if you
    haven't yet):

    releases/2.6.25.7/tcp-fix-skb-vs-fack_count-out-of-sync-condition.patch

    ....If you still get them afterwards, please do rereport (and include me
    as recipient :-)). ...I know there are couple of cases still after that
    fix where TCP invariant checks trigger but they've been rare enough to
    evade any of my debugging attempts (2.6.22.17 won't warn you anyway when
    it breaks an invariant though I already know a handful violations that
    do occur with it too but there's just plain silence because I only later
    on added those warning).


    --
    i.
    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

  5. Re: 2.6.25.6: warn_on_slowpath in tcp_input.c

    On Thu, 17 Jul 2008, Ilpo Järvinen wrote:
    > > > > I've had 13 or so of them since upgrading the machine to a 2.6.25 kernel
    > > > > 20 days ago.
    > > > >
    > > > > Linux saens 2.6.25.6-dl380 #2 SMP Tue Jun 10 17:54:44 CEST 2008 i686 GNU/Linux

    >
    > Thanks for the report, I've been away for a while, thus the late response.
    > Please update to get this relevant fix and some other TCP fixes (if you
    > haven't yet):
    >
    > releases/2.6.25.7/tcp-fix-skb-vs-fack_count-out-of-sync-condition.patch
    >
    > ...If you still get them afterwards, please do rereport (and include me
    > as recipient :-)).


    Running 2.6.25.11 since a couple of days ago now. Looking good, thanks.

    --
    | .''`. ** Debian GNU/Linux **
    Peter Palfrader | : :' : The universal
    http://www.palfrader.org/ | `. `' Operating System
    | `- http://www.debian.org/
    --
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

+ Reply to Thread