panics in tcp_ack

panics in tcp_ack

[Rob Herring]

Sorry, this time with proper line wrapping...

I'm debugging a kernel panic in the networking stack that happens with a
cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
typically only after 10-24 hours. The node are transferring files
between nodes over TCP with 20 clients and servers per node. The kernel
is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
bisect have not yielded results as it seems multiple problems mask the
issue. Perhaps there is some new feature which has indirectly fixed the
problem in 3.8.

This commit appears to fix a similar panic and seems to reduce the
frequency after picking it up in the latest 3.5 stable:

commit 16fad69cfe4adbbfa813de516757b87bcae36d93
Author: Eric Dumazet <edumazet@google.com>
Date:   Thu Mar 14 05:40:32 2013 +0000

    tcp: fix skb_availroom()
        Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
        https://code.google.com/p/chromium/issues/detail?id=182056
        commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
    path) did a poor choice adding an 'avail_size' field to skb, while
    what we really needed was a 'reserved_tailroom' one.
        It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
    partially acked frames) and this commit.
        Crash occurs because skb_split() is not aware of the 'avail_size'
    management (and should not be aware)
        Signed-off-by: Eric Dumazet <edumazet@google.com>
    Reported-by: Mukesh Agrawal <quiche@chromium.org>
    Signed-off-by: David S. Miller <davem@davemloft.net>

I've searched thru 3.8 and 3.9 stable fixes looking for possibly
relevant commits and applied these commits not in 3.5 stable. However,
they have not helped:

net: drop dst before queueing fragments
tcp: call tcp_replace_ts_recent() from tcp_ack()
tcp: Reallocate headroom if it would overflow csum_start
tcp: incoming connections might use wrong route under synflood


The exact panic varies some, but is typically in tcp_ack. I've gotten
this one several times:

<4>[17360.343983] [<c0405e08>] (tcp_fastretrans_alert+0x134/0xbec) from
[<c0406e98>] (tcp_ack+0x540/0x1014)
<4>[17360.353216] [<c0406e98>] (tcp_ack+0x540/0x1014) from [<c0407cb4>]
(tcp_rcv_established+0x348/0x5e0)
<4>[17360.362276] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
[<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
<4>[17360.371679] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
[<c04111ac>] (tcp_v4_rcv+0x814/0x8e8)
<4>[17360.380307] [<c04111ac>] (tcp_v4_rcv+0x814/0x8e8) from
[<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
<4>[17360.389796] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
[<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
<4>[17360.399552] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
[<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
<4>[17360.409045] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
[<c03c06e8>] (netif_receive_skb+0x1c/0x90)
<4>[17360.418708] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
[<c03c2fac>] (napi_skb_finish+0x54/0x78)
<4>[17360.427855] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
[<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
<4>[17360.436567] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
[<c03c2758>] (net_rx_action+0x140/0x228)
<4>[17360.445280] [<c03c2758>] (net_rx_action+0x140/0x228) from
[<c002ac94>] (__do_softirq+0xb4/0x1cc)
<4>[17360.454078] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
[<c002b18c>] (irq_exit+0x80/0x88)
<4>[17360.462269] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
(handle_IRQ+0x50/0xb0)
<4>[17360.470197] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
(gic_handle_irq+0x24/0x58)
<4>[17360.478645] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
[<c049e1fc>] (__irq_usr+0x3c/0x60)
<4>[17360.486994] Exception stack(0xeda89fb0 to 0xeda89ff8)
<4>[17360.492042] 9fa0:                                     b6e0c1cc
0000c004 00000000 0000001c
<4>[17360.500217] 9fc0: 00000000 00000000 0000007c 0012d175 0012d174
ffffffff 0012d175 b692caf0
<4>[17360.508393] 9fe0: 001a3340 bead3758 0007bfab 0007bfb0 800f0030
ffffffff
<0>[17360.515011] Code: e595c2bc e1510000 e5960000 03a01000 (e5911038)
<4>[17360.521207] ---[ end trace 98dabb30d5917f53 ]---

This appears to be a NULL returned from tcp_write_queue_head. I
reconstructed the full stack which looks like this:

tcp_write_queue_head(sk) tcp_skb_timedout
tcp_head_timedout
tcp_time_to_recover
tcp_fastretrans_alert


Searching for similar panics I found this debug patch:

http://www.spinics.net/lists/mm-commits/msg49089.html

With the initial patch, I got continuous spewing of debug due to
"fackets != tp->fackets_out", so I removed some of the checks and now
just get these dumps. I'm not sure if there is anything relevant here
and none of the warnings are triggered:

[12622.995006] P: 28 L: 7 vs 7 S: 5 vs 5 F: 12 vs 12 w:
1697479957-1697494437 (5)
[12623.002273] skb 0 def35f80
[12623.004978] skb 1 def373c0
[12623.007676] skb 2 def346c0
[12623.010374] skb 3 e1b42400
[12623.013092] skb 4 e1b40000
[12623.015794] skb 5 e1b41680
[12623.018490] skb 6 e1b418c0
[12623.021190] skb 7 e1b42f40
[12623.023908] skb 8 dec51680
[12623.026608] skb 9 dec7b600
[12623.029306] skb 10 e0505f80
[12623.032105] skb 11 dec786c0
[12623.034892] skb 12 dec7a880
[12623.037676] skb 13 dec7b840
[12623.040460] skb 14 dec78d80
[12623.043263] skb 15 e0430900
[12623.046050] skb 16 e0431440
[12623.048835] skb 17 e04321c0
[12623.051618] skb 18 e04318c0
[12623.054422] skb 19 e0433a80
[12623.057208] skb 20 e04333c0
[12623.059991] skb 21 e0432640
[12623.062792] head 22 e040df80
[12623.065667] skb 23 e0542ac0
[12623.068453] skb 24 e0431200
[12623.071239] skb 25 e040f600
[12623.074041] TCP wq(s) LLLLLLLSSSSS                <
[12623.078910] TCP wq(h) ++++++++----++++++h+-++++++-<
[12623.083792] l7 s5 f12 p28 seq: su1697479957 hs1697479957 sn1697494437

[18018.368510] P: 24 L: 10 vs 10 S: 6 vs 6 F: 13 vs 13 w:
524404136-524415720 (7)
[18018.375788] skb 0 e9742f40
[18018.378495] skb 1 e9741d40
[18018.381194] skb 2 e0473a80
[18018.383915] skb 3 e0470fc0
[18018.386621] skb 4 e0472f40
[18018.389320] skb 5 e04706c0
[18018.392035] skb 6 e0473180
[18018.394736] skb 7 e054af40
[18018.397435] skb 8 deeae400
[18018.400133] skb 9 e19e86c0
[18018.402854] skb 10 e19e98c0
[18018.405643] skb 11 e0472880
[18018.408429] skb 12 e19eaf40
[18018.411216] head 13 e19eb180
[18018.414116] skb 14 e055c000
[18018.416913] TCP wq(s) LLLLLLLSSSSSSLLL        <
[18018.421439] TCP wq(h) ++++++++-----+++h---+---<
[18018.425999] l10 s6 f13 p24 seq: su524404136 hs524404136 sn524415720

The current 3.5 tree I'm testing is available here:

git://sources.calxeda.com/linux/kernel.git 3.5-net-debug

Rob

Re: panics in tcp_ack

[Eric Dumazet]

On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
> Sorry, this time with proper line wrapping...
> 
> I'm debugging a kernel panic in the networking stack that happens with a
> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
> typically only after 10-24 hours. The node are transferring files
> between nodes over TCP with 20 clients and servers per node. The kernel
> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
> bisect have not yielded results as it seems multiple problems mask the
> issue. Perhaps there is some new feature which has indirectly fixed the
> problem in 3.8.
> 
> This commit appears to fix a similar panic and seems to reduce the
> frequency after picking it up in the latest 3.5 stable:
> 
> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
> Author: Eric Dumazet <edumazet@google.com>
> Date:   Thu Mar 14 05:40:32 2013 +0000
> 
>     tcp: fix skb_availroom()
>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
>         https://code.google.com/p/chromium/issues/detail?id=182056
>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
>     path) did a poor choice adding an 'avail_size' field to skb, while
>     what we really needed was a 'reserved_tailroom' one.
>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
>     partially acked frames) and this commit.
>         Crash occurs because skb_split() is not aware of the 'avail_size'
>     management (and should not be aware)
>         Signed-off-by: Eric Dumazet <edumazet@google.com>
>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
>     Signed-off-by: David S. Miller <davem@davemloft.net>
> 
> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
> relevant commits and applied these commits not in 3.5 stable. However,
> they have not helped:
> 
> net: drop dst before queueing fragments
> tcp: call tcp_replace_ts_recent() from tcp_ack()
> tcp: Reallocate headroom if it would overflow csum_start
> tcp: incoming connections might use wrong route under synflood
> 
> 
> The exact panic varies some, but is typically in tcp_ack. I've gotten
> this one several times:
> 
> <4>[17360.343983] [<c0405e08>] (tcp_fastretrans_alert+0x134/0xbec) from
> [<c0406e98>] (tcp_ack+0x540/0x1014)
> <4>[17360.353216] [<c0406e98>] (tcp_ack+0x540/0x1014) from [<c0407cb4>]
> (tcp_rcv_established+0x348/0x5e0)
> <4>[17360.362276] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
> <4>[17360.371679] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
> [<c04111ac>] (tcp_v4_rcv+0x814/0x8e8)
> <4>[17360.380307] [<c04111ac>] (tcp_v4_rcv+0x814/0x8e8) from
> [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
> <4>[17360.389796] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
> [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
> <4>[17360.399552] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
> [<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
> <4>[17360.409045] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
> [<c03c06e8>] (netif_receive_skb+0x1c/0x90)
> <4>[17360.418708] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
> [<c03c2fac>] (napi_skb_finish+0x54/0x78)
> <4>[17360.427855] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
> [<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
> <4>[17360.436567] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
> [<c03c2758>] (net_rx_action+0x140/0x228)
> <4>[17360.445280] [<c03c2758>] (net_rx_action+0x140/0x228) from
> [<c002ac94>] (__do_softirq+0xb4/0x1cc)
> <4>[17360.454078] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
> [<c002b18c>] (irq_exit+0x80/0x88)
> <4>[17360.462269] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
> (handle_IRQ+0x50/0xb0)
> <4>[17360.470197] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
> (gic_handle_irq+0x24/0x58)
> <4>[17360.478645] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
> [<c049e1fc>] (__irq_usr+0x3c/0x60)
> <4>[17360.486994] Exception stack(0xeda89fb0 to 0xeda89ff8)
> <4>[17360.492042] 9fa0:                                     b6e0c1cc
> 0000c004 00000000 0000001c
> <4>[17360.500217] 9fc0: 00000000 00000000 0000007c 0012d175 0012d174
> ffffffff 0012d175 b692caf0
> <4>[17360.508393] 9fe0: 001a3340 bead3758 0007bfab 0007bfb0 800f0030
> ffffffff
> <0>[17360.515011] Code: e595c2bc e1510000 e5960000 03a01000 (e5911038)
> <4>[17360.521207] ---[ end trace 98dabb30d5917f53 ]---
> 
> This appears to be a NULL returned from tcp_write_queue_head. I
> reconstructed the full stack which looks like this:
> 
> tcp_write_queue_head(sk) tcp_skb_timedout
> tcp_head_timedout
> tcp_time_to_recover
> tcp_fastretrans_alert
> 
> 
> Searching for similar panics I found this debug patch:
> 
> http://www.spinics.net/lists/mm-commits/msg49089.html
> 
> With the initial patch, I got continuous spewing of debug due to
> "fackets != tp->fackets_out", so I removed some of the checks and now
> just get these dumps. I'm not sure if there is anything relevant here
> and none of the warnings are triggered:
> 
> [12622.995006] P: 28 L: 7 vs 7 S: 5 vs 5 F: 12 vs 12 w:
> 1697479957-1697494437 (5)
> [12623.002273] skb 0 def35f80
> [12623.004978] skb 1 def373c0
> [12623.007676] skb 2 def346c0
> [12623.010374] skb 3 e1b42400
> [12623.013092] skb 4 e1b40000
> [12623.015794] skb 5 e1b41680
> [12623.018490] skb 6 e1b418c0
> [12623.021190] skb 7 e1b42f40
> [12623.023908] skb 8 dec51680
> [12623.026608] skb 9 dec7b600
> [12623.029306] skb 10 e0505f80
> [12623.032105] skb 11 dec786c0
> [12623.034892] skb 12 dec7a880
> [12623.037676] skb 13 dec7b840
> [12623.040460] skb 14 dec78d80
> [12623.043263] skb 15 e0430900
> [12623.046050] skb 16 e0431440
> [12623.048835] skb 17 e04321c0
> [12623.051618] skb 18 e04318c0
> [12623.054422] skb 19 e0433a80
> [12623.057208] skb 20 e04333c0
> [12623.059991] skb 21 e0432640
> [12623.062792] head 22 e040df80
> [12623.065667] skb 23 e0542ac0
> [12623.068453] skb 24 e0431200
> [12623.071239] skb 25 e040f600
> [12623.074041] TCP wq(s) LLLLLLLSSSSS                <
> [12623.078910] TCP wq(h) ++++++++----++++++h+-++++++-<
> [12623.083792] l7 s5 f12 p28 seq: su1697479957 hs1697479957 sn1697494437
> 
> [18018.368510] P: 24 L: 10 vs 10 S: 6 vs 6 F: 13 vs 13 w:
> 524404136-524415720 (7)
> [18018.375788] skb 0 e9742f40
> [18018.378495] skb 1 e9741d40
> [18018.381194] skb 2 e0473a80
> [18018.383915] skb 3 e0470fc0
> [18018.386621] skb 4 e0472f40
> [18018.389320] skb 5 e04706c0
> [18018.392035] skb 6 e0473180
> [18018.394736] skb 7 e054af40
> [18018.397435] skb 8 deeae400
> [18018.400133] skb 9 e19e86c0
> [18018.402854] skb 10 e19e98c0
> [18018.405643] skb 11 e0472880
> [18018.408429] skb 12 e19eaf40
> [18018.411216] head 13 e19eb180
> [18018.414116] skb 14 e055c000
> [18018.416913] TCP wq(s) LLLLLLLSSSSSSLLL        <
> [18018.421439] TCP wq(h) ++++++++-----+++h---+---<
> [18018.425999] l10 s6 f13 p24 seq: su524404136 hs524404136 sn524415720
> 
> The current 3.5 tree I'm testing is available here:
> 

Well, please tell us if current kernel (3.10 or 3.9) reproduces the bug.

Re: panics in tcp_ack

[Eric Dumazet]

On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
> Sorry, this time with proper line wrapping...
> 
> I'm debugging a kernel panic in the networking stack that happens with a
> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
> typically only after 10-24 hours. The node are transferring files
> between nodes over TCP with 20 clients and servers per node. The kernel
> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
> bisect have not yielded results as it seems multiple problems mask the
> issue. Perhaps there is some new feature which has indirectly fixed the
> problem in 3.8.

Oh well, you said it was fixed in 3.8, sorry for my prior mail.

Re: panics in tcp_ack

[Eric Dumazet]

On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
> Sorry, this time with proper line wrapping...
> 
> I'm debugging a kernel panic in the networking stack that happens with a
> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
> typically only after 10-24 hours. The node are transferring files
> between nodes over TCP with 20 clients and servers per node. The kernel
> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
> bisect have not yielded results as it seems multiple problems mask the
> issue. Perhaps there is some new feature which has indirectly fixed the
> problem in 3.8.
> 
> This commit appears to fix a similar panic and seems to reduce the
> frequency after picking it up in the latest 3.5 stable:
> 
> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
> Author: Eric Dumazet <edumazet@google.com>
> Date:   Thu Mar 14 05:40:32 2013 +0000
> 
>     tcp: fix skb_availroom()
>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
>         https://code.google.com/p/chromium/issues/detail?id=182056
>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
>     path) did a poor choice adding an 'avail_size' field to skb, while
>     what we really needed was a 'reserved_tailroom' one.
>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
>     partially acked frames) and this commit.
>         Crash occurs because skb_split() is not aware of the 'avail_size'
>     management (and should not be aware)
>         Signed-off-by: Eric Dumazet <edumazet@google.com>
>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
>     Signed-off-by: David S. Miller <davem@davemloft.net>
> 
> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
> relevant commits and applied these commits not in 3.5 stable. However,
> they have not helped:
> 
> net: drop dst before queueing fragments
> tcp: call tcp_replace_ts_recent() from tcp_ack()
> tcp: Reallocate headroom if it would overflow csum_start
> tcp: incoming connections might use wrong route under synflood
> 

try also :

commit 093162553c33e94 (tcp: force a dst refcount when prequeue packet)
commit 0d4f0608619de59 (tcp: dont handle MTU reduction on LISTEN socket)
commit 6731d2095bd4aef (tcp: fix for zero packets_in_flight was too
broad)
commit 2e5f421211ff76c (tcp: frto should not set snd_cwnd to 0)

Re: panics in tcp_ack

[Rob Herring]

On 06/02/2013 07:36 PM, Eric Dumazet wrote:
> On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
>> Sorry, this time with proper line wrapping...
>>
>> I'm debugging a kernel panic in the networking stack that happens with a
>> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
>> typically only after 10-24 hours. The node are transferring files
>> between nodes over TCP with 20 clients and servers per node. The kernel
>> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
>> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
>> bisect have not yielded results as it seems multiple problems mask the
>> issue. Perhaps there is some new feature which has indirectly fixed the
>> problem in 3.8.
>>
>> This commit appears to fix a similar panic and seems to reduce the
>> frequency after picking it up in the latest 3.5 stable:
>>
>> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
>> Author: Eric Dumazet <edumazet@google.com>
>> Date:   Thu Mar 14 05:40:32 2013 +0000
>>
>>     tcp: fix skb_availroom()
>>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
>>         https://code.google.com/p/chromium/issues/detail?id=182056
>>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
>>     path) did a poor choice adding an 'avail_size' field to skb, while
>>     what we really needed was a 'reserved_tailroom' one.
>>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
>>     partially acked frames) and this commit.
>>         Crash occurs because skb_split() is not aware of the 'avail_size'
>>     management (and should not be aware)
>>         Signed-off-by: Eric Dumazet <edumazet@google.com>
>>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
>>     Signed-off-by: David S. Miller <davem@davemloft.net>
>>
>> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
>> relevant commits and applied these commits not in 3.5 stable. However,
>> they have not helped:
>>
>> net: drop dst before queueing fragments
>> tcp: call tcp_replace_ts_recent() from tcp_ack()
>> tcp: Reallocate headroom if it would overflow csum_start
>> tcp: incoming connections might use wrong route under synflood
>>
> 
> try also :
> 
> commit 093162553c33e94 (tcp: force a dst refcount when prequeue packet)
> commit 0d4f0608619de59 (tcp: dont handle MTU reduction on LISTEN socket)

Will add and test.

> commit 6731d2095bd4aef (tcp: fix for zero packets_in_flight was too
> broad)
> commit 2e5f421211ff76c (tcp: frto should not set snd_cwnd to 0)

I have these 2.

Meanwhile, here's another panic. This one is because struct tcphdr *th
is NULL which means skb->head is NULL. The skb is not NULL.

<4>[84967.163498] pc : [<c040798c>]    lr : [<c040eda8>]    psr: 600e0013
<4>[84967.163498] sp : ed335cc8  ip : 00000001  fp : 00000400
<4>[84967.174970] r10: ed346e34  r9 : 00000001  r8 : c06d71b8
<4>[84967.180188] r7 : 00000000  r6 : 00000000  r5 : ecd85840  r4 : ecd85840
<4>[84967.186709] r3 : 00000020  r2 : 0000003a  r1 : a4051080  r0 : ed346e00
<4>[84967.193234] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM
Segment user
<4>[84967.200365] Control: 10c5387d  Table: 2d08804a  DAC: 00000015
<0>[84967.206109] Process python (pid: 883, stack limit = 0xed3342f0)
<0>[84967.212021] Stack: (0xed335cc8 to 0xed336000)
<0>[84967.216373] 5cc0:                   000005a8 00000000 ed346e00
c040ac08 c06a5a00 ecd85840
<0>[84967.224549] 5ce0: ed346e00 ed346e00 00000000 c06d71b8 ed346e34
c040eda8 ed346ea0 00000000
<0>[84967.232720] 5d00: 00000000 00000000 e9805380 0000000a 0000001c
ecd85840 00000000 ed346e00
<0>[84967.240897] 5d20: 00000000 c03b1d78 e9805380 ed346e00 0000fe88
3a61054b 00000400 00df2c34
<0>[84967.249075] 5d40: 00000040 c03fd2b8 0000a400 edf8c840 ed335eb0
ed335ed8 c23212f0 c23212e0
<0>[84967.257249] 5d60: 00df2c34 c17720e0 0000000e 00000400 00000400
000005a8 00000040 ed346ea0
<0>[84967.265419] 5d80: 00000000 00000000 ed334000 00000001 00010e30
00000630 00000000 00000000
<0>[84967.273591] 5da0: 0000000e 0000fe88 00000000 c06d6040 c2aeb380
ed346e00 ed335e30 eca26000
<0>[84967.281763] 5dc0: ed335ed8 00000400 00df2834 00000000 00000003
c041ea58 c795c2e8 ed4ecb50
<0>[84967.289935] 5de0: 00000000 ed335df0 eca26000 c03aef74 51ab6eeb
263fddc0 00000000 00000400
<0>[84967.298105] 5e00: eca26000 00000000 00000000 ed335ed8 01d0d6eb
c00cb4d8 00000056 00000000
<0>[84967.306294] 5e20: 91827364 ed335e24 00001000 00000001 ed9b4050
00000000 00000000 00000001
<0>[84967.314472] 5e40: ffffffff 00000000 00000000 00000000 00000000
00000000 ecc3de80 00000001
<0>[84967.322642] 5e60: 00000000 00000000 00001000 00000000 ed335df0
00000000 00001000 c0012f28
<0>[84967.330812] 5e80: fee00100 0002c000 00000000 ed335f88 ed9b4000
fffffdee ed334000 00000001
<0>[84967.338983] 5ea0: b6ae35f8 c010aa38 0002c000 00000000 00000400
eca26000 c06a4508 00000000
<0>[84967.347152] 5ec0: 00000040 c03b07d4 fffffff7 00000000 00df2834
00000400 00000000 00000000
<0>[84967.355321] 5ee0: ed335ed0 00000001 00000000 00000000 00000040
00000000 00000000 c0223254
<0>[84967.363495] 5f00: 00001000 00000000 00001000 00000000 00000001
ed9b4008 600e0013 ffffffff
<0>[84967.371666] 5f20: c000dbc4 c06ff504 ffffffff 00000000 00014be7
03614c11 ed335f90 00000000
<0>[84967.379858] 5f40: 0000000a ed335f68 c000dd28 ed334000 00000000
00000003 0000000a 0000000a
<0>[84967.388032] 5f60: 00000000 0002c000 00014bf1 00002710 00000001
271ae81b b6aecd90 00000000
<0>[84967.396203] 5f80: 00d25050 00000121 c000dd28 ed334000 00000000
c03b0828 00000000 00000000
<0>[84967.404376] 5fa0: be8f2890 c000db60 b6aecd90 00000000 00000006
00df2834 00000400 00000000
<0>[84967.412547] 5fc0: b6aecd90 00000000 00d25050 00000121 00000400
00df2834 b6ad4fd0 00000003
<0>[84967.420719] 5fe0: 00000000 be8f289c 000a5505 b6f7398c 600e0010
00000006 00000000 00000000
<4>[84967.428912] [<c040798c>] (tcp_rcv_established+0x20/0x5e0) from
[<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
<4>[84967.438252] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
[<c03b1d78>] (release_sock+0x84/0xfc)
<4>[84967.446900] [<c03b1d78>] (release_sock+0x84/0xfc) from
[<c03fd2b8>] (tcp_sendmsg+0x378/0xcdc)
<4>[84967.455439] [<c03fd2b8>] (tcp_sendmsg+0x378/0xcdc) from
[<c041ea58>] (inet_sendmsg+0x80/0xb8)
<4>[84967.463966] [<c041ea58>] (inet_sendmsg+0x80/0xb8) from
[<c03aef74>] (sock_sendmsg+0xcc/0xec)
<4>[84967.472404] [<c03aef74>] (sock_sendmsg+0xcc/0xec) from
[<c03b07d4>] (sys_sendto+0xc0/0xfc)
<4>[84967.480670] [<c03b07d4>] (sys_sendto+0xc0/0xfc) from [<c03b0828>]
(sys_send+0x18/0x20)
<4>[84967.488599] [<c03b0828>] (sys_send+0x18/0x20) from [<c000db60>]
(ret_fast_syscall+0x0/0x30)


Rob

Re: panics in tcp_ack

[Eric Dumazet]

On Sun, 2013-06-02 at 21:23 -0500, Rob Herring wrote:

> Meanwhile, here's another panic. This one is because struct tcphdr *th
> is NULL which means skb->head is NULL. The skb is not NULL.
> 
> <4>[84967.163498] pc : [<c040798c>]    lr : [<c040eda8>]    psr: 600e0013
> <4>[84967.163498] sp : ed335cc8  ip : 00000001  fp : 00000400
> <4>[84967.174970] r10: ed346e34  r9 : 00000001  r8 : c06d71b8
> <4>[84967.180188] r7 : 00000000  r6 : 00000000  r5 : ecd85840  r4 : ecd85840
> <4>[84967.186709] r3 : 00000020  r2 : 0000003a  r1 : a4051080  r0 : ed346e00
> <4>[84967.193234] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM
> Segment user
> <4>[84967.200365] Control: 10c5387d  Table: 2d08804a  DAC: 00000015
> <0>[84967.206109] Process python (pid: 883, stack limit = 0xed3342f0)
> <0>[84967.212021] Stack: (0xed335cc8 to 0xed336000)
> <0>[84967.216373] 5cc0:                   000005a8 00000000 ed346e00
> c040ac08 c06a5a00 ecd85840
> <0>[84967.224549] 5ce0: ed346e00 ed346e00 00000000 c06d71b8 ed346e34
> c040eda8 ed346ea0 00000000
> <0>[84967.232720] 5d00: 00000000 00000000 e9805380 0000000a 0000001c
> ecd85840 00000000 ed346e00
> <0>[84967.240897] 5d20: 00000000 c03b1d78 e9805380 ed346e00 0000fe88
> 3a61054b 00000400 00df2c34
> <0>[84967.249075] 5d40: 00000040 c03fd2b8 0000a400 edf8c840 ed335eb0
> ed335ed8 c23212f0 c23212e0
> <0>[84967.257249] 5d60: 00df2c34 c17720e0 0000000e 00000400 00000400
> 000005a8 00000040 ed346ea0
> <0>[84967.265419] 5d80: 00000000 00000000 ed334000 00000001 00010e30
> 00000630 00000000 00000000
> <0>[84967.273591] 5da0: 0000000e 0000fe88 00000000 c06d6040 c2aeb380
> ed346e00 ed335e30 eca26000
> <0>[84967.281763] 5dc0: ed335ed8 00000400 00df2834 00000000 00000003
> c041ea58 c795c2e8 ed4ecb50
> <0>[84967.289935] 5de0: 00000000 ed335df0 eca26000 c03aef74 51ab6eeb
> 263fddc0 00000000 00000400
> <0>[84967.298105] 5e00: eca26000 00000000 00000000 ed335ed8 01d0d6eb
> c00cb4d8 00000056 00000000
> <0>[84967.306294] 5e20: 91827364 ed335e24 00001000 00000001 ed9b4050
> 00000000 00000000 00000001
> <0>[84967.314472] 5e40: ffffffff 00000000 00000000 00000000 00000000
> 00000000 ecc3de80 00000001
> <0>[84967.322642] 5e60: 00000000 00000000 00001000 00000000 ed335df0
> 00000000 00001000 c0012f28
> <0>[84967.330812] 5e80: fee00100 0002c000 00000000 ed335f88 ed9b4000
> fffffdee ed334000 00000001
> <0>[84967.338983] 5ea0: b6ae35f8 c010aa38 0002c000 00000000 00000400
> eca26000 c06a4508 00000000
> <0>[84967.347152] 5ec0: 00000040 c03b07d4 fffffff7 00000000 00df2834
> 00000400 00000000 00000000
> <0>[84967.355321] 5ee0: ed335ed0 00000001 00000000 00000000 00000040
> 00000000 00000000 c0223254
> <0>[84967.363495] 5f00: 00001000 00000000 00001000 00000000 00000001
> ed9b4008 600e0013 ffffffff
> <0>[84967.371666] 5f20: c000dbc4 c06ff504 ffffffff 00000000 00014be7
> 03614c11 ed335f90 00000000
> <0>[84967.379858] 5f40: 0000000a ed335f68 c000dd28 ed334000 00000000
> 00000003 0000000a 0000000a
> <0>[84967.388032] 5f60: 00000000 0002c000 00014bf1 00002710 00000001
> 271ae81b b6aecd90 00000000
> <0>[84967.396203] 5f80: 00d25050 00000121 c000dd28 ed334000 00000000
> c03b0828 00000000 00000000
> <0>[84967.404376] 5fa0: be8f2890 c000db60 b6aecd90 00000000 00000006
> 00df2834 00000400 00000000
> <0>[84967.412547] 5fc0: b6aecd90 00000000 00d25050 00000121 00000400
> 00df2834 b6ad4fd0 00000003
> <0>[84967.420719] 5fe0: 00000000 be8f289c 000a5505 b6f7398c 600e0010
> 00000006 00000000 00000000
> <4>[84967.428912] [<c040798c>] (tcp_rcv_established+0x20/0x5e0) from
> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
> <4>[84967.438252] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
> [<c03b1d78>] (release_sock+0x84/0xfc)
> <4>[84967.446900] [<c03b1d78>] (release_sock+0x84/0xfc) from
> [<c03fd2b8>] (tcp_sendmsg+0x378/0xcdc)
> <4>[84967.455439] [<c03fd2b8>] (tcp_sendmsg+0x378/0xcdc) from
> [<c041ea58>] (inet_sendmsg+0x80/0xb8)
> <4>[84967.463966] [<c041ea58>] (inet_sendmsg+0x80/0xb8) from
> [<c03aef74>] (sock_sendmsg+0xcc/0xec)
> <4>[84967.472404] [<c03aef74>] (sock_sendmsg+0xcc/0xec) from
> [<c03b07d4>] (sys_sendto+0xc0/0xfc)
> <4>[84967.480670] [<c03b07d4>] (sys_sendto+0xc0/0xfc) from [<c03b0828>]
> (sys_send+0x18/0x20)
> <4>[84967.488599] [<c03b0828>] (sys_send+0x18/0x20) from [<c000db60>]
> (ret_fast_syscall+0x0/0x30)
> 

Hmm, skb->head being NULL, are you really really sure ???

Re: panics in tcp_ack

[Rob Herring]

On 06/02/2013 10:03 PM, Eric Dumazet wrote:
> On Sun, 2013-06-02 at 21:23 -0500, Rob Herring wrote:
> 
>> Meanwhile, here's another panic. This one is because struct tcphdr *th
>> is NULL which means skb->head is NULL. The skb is not NULL.
>>
>> <4>[84967.163498] pc : [<c040798c>]    lr : [<c040eda8>]    psr: 600e0013
>> <4>[84967.163498] sp : ed335cc8  ip : 00000001  fp : 00000400
>> <4>[84967.174970] r10: ed346e34  r9 : 00000001  r8 : c06d71b8
>> <4>[84967.180188] r7 : 00000000  r6 : 00000000  r5 : ecd85840  r4 : ecd85840
>> <4>[84967.186709] r3 : 00000020  r2 : 0000003a  r1 : a4051080  r0 : ed346e00
>> <4>[84967.193234] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM
>> Segment user
>> <4>[84967.200365] Control: 10c5387d  Table: 2d08804a  DAC: 00000015
>> <0>[84967.206109] Process python (pid: 883, stack limit = 0xed3342f0)
>> <0>[84967.212021] Stack: (0xed335cc8 to 0xed336000)
>> <0>[84967.216373] 5cc0:                   000005a8 00000000 ed346e00
>> c040ac08 c06a5a00 ecd85840
>> <0>[84967.224549] 5ce0: ed346e00 ed346e00 00000000 c06d71b8 ed346e34
>> c040eda8 ed346ea0 00000000
>> <0>[84967.232720] 5d00: 00000000 00000000 e9805380 0000000a 0000001c
>> ecd85840 00000000 ed346e00
>> <0>[84967.240897] 5d20: 00000000 c03b1d78 e9805380 ed346e00 0000fe88
>> 3a61054b 00000400 00df2c34
>> <0>[84967.249075] 5d40: 00000040 c03fd2b8 0000a400 edf8c840 ed335eb0
>> ed335ed8 c23212f0 c23212e0
>> <0>[84967.257249] 5d60: 00df2c34 c17720e0 0000000e 00000400 00000400
>> 000005a8 00000040 ed346ea0
>> <0>[84967.265419] 5d80: 00000000 00000000 ed334000 00000001 00010e30
>> 00000630 00000000 00000000
>> <0>[84967.273591] 5da0: 0000000e 0000fe88 00000000 c06d6040 c2aeb380
>> ed346e00 ed335e30 eca26000
>> <0>[84967.281763] 5dc0: ed335ed8 00000400 00df2834 00000000 00000003
>> c041ea58 c795c2e8 ed4ecb50
>> <0>[84967.289935] 5de0: 00000000 ed335df0 eca26000 c03aef74 51ab6eeb
>> 263fddc0 00000000 00000400
>> <0>[84967.298105] 5e00: eca26000 00000000 00000000 ed335ed8 01d0d6eb
>> c00cb4d8 00000056 00000000
>> <0>[84967.306294] 5e20: 91827364 ed335e24 00001000 00000001 ed9b4050
>> 00000000 00000000 00000001
>> <0>[84967.314472] 5e40: ffffffff 00000000 00000000 00000000 00000000
>> 00000000 ecc3de80 00000001
>> <0>[84967.322642] 5e60: 00000000 00000000 00001000 00000000 ed335df0
>> 00000000 00001000 c0012f28
>> <0>[84967.330812] 5e80: fee00100 0002c000 00000000 ed335f88 ed9b4000
>> fffffdee ed334000 00000001
>> <0>[84967.338983] 5ea0: b6ae35f8 c010aa38 0002c000 00000000 00000400
>> eca26000 c06a4508 00000000
>> <0>[84967.347152] 5ec0: 00000040 c03b07d4 fffffff7 00000000 00df2834
>> 00000400 00000000 00000000
>> <0>[84967.355321] 5ee0: ed335ed0 00000001 00000000 00000000 00000040
>> 00000000 00000000 c0223254
>> <0>[84967.363495] 5f00: 00001000 00000000 00001000 00000000 00000001
>> ed9b4008 600e0013 ffffffff
>> <0>[84967.371666] 5f20: c000dbc4 c06ff504 ffffffff 00000000 00014be7
>> 03614c11 ed335f90 00000000
>> <0>[84967.379858] 5f40: 0000000a ed335f68 c000dd28 ed334000 00000000
>> 00000003 0000000a 0000000a
>> <0>[84967.388032] 5f60: 00000000 0002c000 00014bf1 00002710 00000001
>> 271ae81b b6aecd90 00000000
>> <0>[84967.396203] 5f80: 00d25050 00000121 c000dd28 ed334000 00000000
>> c03b0828 00000000 00000000
>> <0>[84967.404376] 5fa0: be8f2890 c000db60 b6aecd90 00000000 00000006
>> 00df2834 00000400 00000000
>> <0>[84967.412547] 5fc0: b6aecd90 00000000 00d25050 00000121 00000400
>> 00df2834 b6ad4fd0 00000003
>> <0>[84967.420719] 5fe0: 00000000 be8f289c 000a5505 b6f7398c 600e0010
>> 00000006 00000000 00000000
>> <4>[84967.428912] [<c040798c>] (tcp_rcv_established+0x20/0x5e0) from
>> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
>> <4>[84967.438252] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
>> [<c03b1d78>] (release_sock+0x84/0xfc)
>> <4>[84967.446900] [<c03b1d78>] (release_sock+0x84/0xfc) from
>> [<c03fd2b8>] (tcp_sendmsg+0x378/0xcdc)
>> <4>[84967.455439] [<c03fd2b8>] (tcp_sendmsg+0x378/0xcdc) from
>> [<c041ea58>] (inet_sendmsg+0x80/0xb8)
>> <4>[84967.463966] [<c041ea58>] (inet_sendmsg+0x80/0xb8) from
>> [<c03aef74>] (sock_sendmsg+0xcc/0xec)
>> <4>[84967.472404] [<c03aef74>] (sock_sendmsg+0xcc/0xec) from
>> [<c03b07d4>] (sys_sendto+0xc0/0xfc)
>> <4>[84967.480670] [<c03b07d4>] (sys_sendto+0xc0/0xfc) from [<c03b0828>]
>> (sys_send+0x18/0x20)
>> <4>[84967.488599] [<c03b0828>] (sys_send+0x18/0x20) from [<c000db60>]
>> (ret_fast_syscall+0x0/0x30)
>>
> 
> Hmm, skb->head being NULL, are you really really sure ???

Ah, missed that there are 2 versions of skb_transport_header. So on
32-bit it is skb->transport_header.

Here's the ARM disassembly:

c040796c <tcp_rcv_established>:
c040796c:       e92d45f0        push    {r4, r5, r6, r7, r8, sl, lr}
c0407970:       e1a06002        mov     r6, r2
c0407974:       e5d023e4        ldrb    r2, [r0, #996]  ; 0x3e4
c0407978:       e1a05001        mov     r5, r1
c040797c:       e5901344        ldr     r1, [r0, #836]  ; 0x344
c0407980:       e24dd014        sub     sp, sp, #20
c0407984:       e7c0201f        bfc     r2, #0, #1
c0407988:       e5c023e4        strb    r2, [r0, #996]  ; 0x3e4
panic>c040798c:       e596200c        ldr     r2, [r6, #12]

r6 is NULL. r6 came from r2 which is the 3rd function argument.

The 3rd arg is tcp_hdr(skb) which is skb->transport_header.

Rob

Re: panics in tcp_ack

[Eric Dumazet]

On Sun, 2013-06-02 at 22:18 -0500, Rob Herring wrote:

> Ah, missed that there are 2 versions of skb_transport_header. So on
> 32-bit it is skb->transport_header.
> 
> Here's the ARM disassembly:
> 
> c040796c <tcp_rcv_established>:
> c040796c:       e92d45f0        push    {r4, r5, r6, r7, r8, sl, lr}
> c0407970:       e1a06002        mov     r6, r2
> c0407974:       e5d023e4        ldrb    r2, [r0, #996]  ; 0x3e4
> c0407978:       e1a05001        mov     r5, r1
> c040797c:       e5901344        ldr     r1, [r0, #836]  ; 0x344
> c0407980:       e24dd014        sub     sp, sp, #20
> c0407984:       e7c0201f        bfc     r2, #0, #1
> c0407988:       e5c023e4        strb    r2, [r0, #996]  ; 0x3e4
> panic>c040798c:       e596200c        ldr     r2, [r6, #12]
> 
> r6 is NULL. r6 came from r2 which is the 3rd function argument.
> 
> The 3rd arg is tcp_hdr(skb) which is skb->transport_header.
> 
> Rob

Interesting. transport header should be set in IP stack before TCP.

What is the driver delivering this packet ?

Do you have commit fda55eca5a33f33ffcd4192c6b2d75179714a52c
("net: introduce skb_transport_header_was_set()")

Re: panics in tcp_ack

[Rob Herring]

On 06/02/2013 10:32 PM, Eric Dumazet wrote:
> On Sun, 2013-06-02 at 22:18 -0500, Rob Herring wrote:
> 
>> Ah, missed that there are 2 versions of skb_transport_header. So on
>> 32-bit it is skb->transport_header.
>>
>> Here's the ARM disassembly:
>>
>> c040796c <tcp_rcv_established>:
>> c040796c:       e92d45f0        push    {r4, r5, r6, r7, r8, sl, lr}
>> c0407970:       e1a06002        mov     r6, r2
>> c0407974:       e5d023e4        ldrb    r2, [r0, #996]  ; 0x3e4
>> c0407978:       e1a05001        mov     r5, r1
>> c040797c:       e5901344        ldr     r1, [r0, #836]  ; 0x344
>> c0407980:       e24dd014        sub     sp, sp, #20
>> c0407984:       e7c0201f        bfc     r2, #0, #1
>> c0407988:       e5c023e4        strb    r2, [r0, #996]  ; 0x3e4
>> panic>c040798c:       e596200c        ldr     r2, [r6, #12]
>>
>> r6 is NULL. r6 came from r2 which is the 3rd function argument.
>>
>> The 3rd arg is tcp_hdr(skb) which is skb->transport_header.
>>
>> Rob
> 
> Interesting. transport header should be set in IP stack before TCP.
> 
> What is the driver delivering this packet ?

Calxeda xgmac

> Do you have commit fda55eca5a33f33ffcd4192c6b2d75179714a52c
> ("net: introduce skb_transport_header_was_set()")

No.

Rob

Re: panics in tcp_ack

[Rob Herring]

On 06/02/2013 09:23 PM, Rob Herring wrote:
> On 06/02/2013 07:36 PM, Eric Dumazet wrote:
>> On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
>>> Sorry, this time with proper line wrapping...
>>>
>>> I'm debugging a kernel panic in the networking stack that happens with a
>>> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
>>> typically only after 10-24 hours. The node are transferring files
>>> between nodes over TCP with 20 clients and servers per node. The kernel
>>> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
>>> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
>>> bisect have not yielded results as it seems multiple problems mask the
>>> issue. Perhaps there is some new feature which has indirectly fixed the
>>> problem in 3.8.
>>>
>>> This commit appears to fix a similar panic and seems to reduce the
>>> frequency after picking it up in the latest 3.5 stable:
>>>
>>> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
>>> Author: Eric Dumazet <edumazet@google.com>
>>> Date:   Thu Mar 14 05:40:32 2013 +0000
>>>
>>>     tcp: fix skb_availroom()
>>>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
>>>         https://code.google.com/p/chromium/issues/detail?id=182056
>>>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
>>>     path) did a poor choice adding an 'avail_size' field to skb, while
>>>     what we really needed was a 'reserved_tailroom' one.
>>>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
>>>     partially acked frames) and this commit.
>>>         Crash occurs because skb_split() is not aware of the 'avail_size'
>>>     management (and should not be aware)
>>>         Signed-off-by: Eric Dumazet <edumazet@google.com>
>>>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
>>>     Signed-off-by: David S. Miller <davem@davemloft.net>
>>>
>>> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
>>> relevant commits and applied these commits not in 3.5 stable. However,
>>> they have not helped:
>>>
>>> net: drop dst before queueing fragments
>>> tcp: call tcp_replace_ts_recent() from tcp_ack()
>>> tcp: Reallocate headroom if it would overflow csum_start
>>> tcp: incoming connections might use wrong route under synflood
>>>
>>
>> try also :
>>
>> commit 093162553c33e94 (tcp: force a dst refcount when prequeue packet)
>> commit 0d4f0608619de59 (tcp: dont handle MTU reduction on LISTEN socket)
> 
> Will add and test.
> 
>> commit 6731d2095bd4aef (tcp: fix for zero packets_in_flight was too
>> broad)
>> commit 2e5f421211ff76c (tcp: frto should not set snd_cwnd to 0)
> 
> I have these 2.

Ran overnight with the 2 additional patches. One panic after ~9 hours
running on 75 nodes.

<4>[30632.185861] [<c04070f4>] (tcp_ack+0x79c/0x1014) from [<c0407cb4>]
(tcp_rcv_established+0x348/0x5e0)
<4>[30632.194903] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
[<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
<4>[30632.204291] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
[<c04111cc>] (tcp_v4_rcv+0x834/0x918)
<4>[30632.212900] [<c04111cc>] (tcp_v4_rcv+0x834/0x918) from
[<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
<4>[30632.222376] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
[<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
<4>[30632.232115] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
[<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
<4>[30632.241590] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
[<c03c06e8>] (netif_receive_skb+0x1c/0x90)
<4>[30632.251240] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
[<c03c2fac>] (napi_skb_finish+0x54/0x78)
<4>[30632.260371] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
[<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
<4>[30632.269066] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
[<c03c2758>] (net_rx_action+0x140/0x228)
<4>[30632.277761] [<c03c2758>] (net_rx_action+0x140/0x228) from
[<c002ac94>] (__do_softirq+0xb4/0x1cc)
<4>[30632.286541] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
[<c002b18c>] (irq_exit+0x80/0x88)
<4>[30632.294716] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
(handle_IRQ+0x50/0xb0)
<4>[30632.302629] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
(gic_handle_irq+0x24/0x58)
<4>[30632.311062] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
[<c049e100>] (__irq_svc+0x40/0x50)
<4>[30632.319402] Exception stack(0xeca4dc10 to 0xeca4dc58)
<4>[30632.324445] dc00:                                     c2f7a580
02000020 02000000 00000000
<4>[30632.332615] dc20: c2f7a580 e9e4f33c e9e4f34c 00000000 ec185300
00001000 00000000 00001000
<4>[30632.340783] dc40: 00000001 eca4dc58 c0136cbc c0136cd4 200f0013
ffffffff
<4>[30632.347398] [<c049e100>] (__irq_svc+0x40/0x50) from [<c0136cd4>]
(__set_page_dirty+0x80/0xc0)
<4>[30632.355919] [<c0136cd4>] (__set_page_dirty+0x80/0xc0) from
[<c01387ac>] (__block_commit_write+0xb4/0xe0)
<4>[30632.365394] [<c01387ac>] (__block_commit_write+0xb4/0xe0) from
[<c0138eb4>] (block_write_end+0x4c/0x84)
<4>[30632.374782] [<c0138eb4>] (block_write_end+0x4c/0x84) from
[<c0138f20>] (generic_write_end+0x34/0xb0)
<4>[30632.383911] [<c0138f20>] (generic_write_end+0x34/0xb0) from
[<c01a0b8c>] (ext4_da_write_end+0xa4/0x340)
<4>[30632.393303] [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340) from
[<c00ca2bc>] (generic_file_buffered_write+0xe0/0x25
8)
<4>[30632.403648] [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x258)
from [<c00cb1d8>] (__generic_file_aio_write+0x
274/0x4bc)
<4>[30632.414684] [<c00cb1d8>] (__generic_file_aio_write+0x274/0x4bc)
from [<c00cb47c>] (generic_file_aio_write+0x5c/0
xc8)
<4>[30632.425201] [<c00cb47c>] (generic_file_aio_write+0x5c/0xc8) from
[<c019810c>] (ext4_file_write+0xcc/0x2a0)
<4>[30632.434853] [<c019810c>] (ext4_file_write+0xcc/0x2a0) from
[<c010a950>] (do_sync_write+0xa8/0xe8)
<4>[30632.443722] [<c010a950>] (do_sync_write+0xa8/0xe8) from
[<c010b360>] (vfs_write+0x9c/0x170)
<4>[30632.452069] [<c010b360>] (vfs_write+0x9c/0x170) from [<c010b648>]
(sys_write+0x38/0x70)
<4>[30632.460068] [<c010b648>] (sys_write+0x38/0x70) from [<c000db60>]
(ret_fast_syscall+0x0/0x30)

The full stack looks like this:

include/linux/skbuff.h:__skb_unlink
include/net/tcp.h:tcp_unlink_write_queue
net/ipv4/tcp_input.c:tcp_clean_rtx_queue
net/ipv4/tcp_input.c:tcp_ack

This panic is in __skb_unlink with the skb prev ptr being NULL. Here's
the disassembly:

                if (!fully_acked)
c04070cc:       e3520000        cmp     r2, #0
c04070d0:       0afffecb        beq     c0406c04 <tcp_ack+0x2ac>
extern void        skb_unlink(struct sk_buff *skb, struct sk_buff_head
*list);
static inline void __skb_unlink(struct sk_buff *skb, struct sk_buff_head
*list)
{
        struct sk_buff *next, *prev;

        list->qlen--;
c04070d4:       e59430a8        ldr     r3, [r4, #168]  ; 0xa8
static inline void sk_wmem_free_skb(struct sock *sk, struct sk_buff *skb)
{
        sock_set_flag(sk, SOCK_QUEUE_SHRUNK);
        sk->sk_wmem_queued -= skb->truesize;
        sk_mem_uncharge(sk, skb->truesize);
        __kfree_skb(skb);
c04070d8:       e1a00005        mov     r0, r5
c04070dc:       e2433001        sub     r3, r3, #1
c04070e0:       e58430a8        str     r3, [r4, #168]  ; 0xa8
        next       = skb->next;
        prev       = skb->prev;
c04070e4:       e895000c        ldm     r5, {r2, r3}
        skb->next  = skb->prev = NULL;
c04070e8:       e5859000        str     r9, [r5]
c04070ec:       e5859004        str     r9, [r5, #4]
        next->prev = prev;
c04070f0:       e5823004        str     r3, [r2, #4]
        prev->next = next;
c04070f4:       e5832000        str     r2, [r3]

Rob

Re: panics in tcp_ack

[Eric Dumazet]

On Mon, 2013-06-03 at 08:05 -0500, Rob Herring wrote:
> On 06/02/2013 09:23 PM, Rob Herring wrote:
> > On 06/02/2013 07:36 PM, Eric Dumazet wrote:
> >> On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
> >>> Sorry, this time with proper line wrapping...
> >>>
> >>> I'm debugging a kernel panic in the networking stack that happens with a
> >>> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
> >>> typically only after 10-24 hours. The node are transferring files
> >>> between nodes over TCP with 20 clients and servers per node. The kernel
> >>> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
> >>> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
> >>> bisect have not yielded results as it seems multiple problems mask the
> >>> issue. Perhaps there is some new feature which has indirectly fixed the
> >>> problem in 3.8.
> >>>
> >>> This commit appears to fix a similar panic and seems to reduce the
> >>> frequency after picking it up in the latest 3.5 stable:
> >>>
> >>> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
> >>> Author: Eric Dumazet <edumazet@google.com>
> >>> Date:   Thu Mar 14 05:40:32 2013 +0000
> >>>
> >>>     tcp: fix skb_availroom()
> >>>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
> >>>         https://code.google.com/p/chromium/issues/detail?id=182056
> >>>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
> >>>     path) did a poor choice adding an 'avail_size' field to skb, while
> >>>     what we really needed was a 'reserved_tailroom' one.
> >>>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
> >>>     partially acked frames) and this commit.
> >>>         Crash occurs because skb_split() is not aware of the 'avail_size'
> >>>     management (and should not be aware)
> >>>         Signed-off-by: Eric Dumazet <edumazet@google.com>
> >>>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
> >>>     Signed-off-by: David S. Miller <davem@davemloft.net>
> >>>
> >>> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
> >>> relevant commits and applied these commits not in 3.5 stable. However,
> >>> they have not helped:
> >>>
> >>> net: drop dst before queueing fragments
> >>> tcp: call tcp_replace_ts_recent() from tcp_ack()
> >>> tcp: Reallocate headroom if it would overflow csum_start
> >>> tcp: incoming connections might use wrong route under synflood
> >>>
> >>
> >> try also :
> >>
> >> commit 093162553c33e94 (tcp: force a dst refcount when prequeue packet)
> >> commit 0d4f0608619de59 (tcp: dont handle MTU reduction on LISTEN socket)
> > 
> > Will add and test.
> > 
> >> commit 6731d2095bd4aef (tcp: fix for zero packets_in_flight was too
> >> broad)
> >> commit 2e5f421211ff76c (tcp: frto should not set snd_cwnd to 0)
> > 
> > I have these 2.
> 
> Ran overnight with the 2 additional patches. One panic after ~9 hours
> running on 75 nodes.
> 
> <4>[30632.185861] [<c04070f4>] (tcp_ack+0x79c/0x1014) from [<c0407cb4>]
> (tcp_rcv_established+0x348/0x5e0)
> <4>[30632.194903] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
> <4>[30632.204291] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
> [<c04111cc>] (tcp_v4_rcv+0x834/0x918)
> <4>[30632.212900] [<c04111cc>] (tcp_v4_rcv+0x834/0x918) from
> [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
> <4>[30632.222376] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
> [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
> <4>[30632.232115] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
> [<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
> <4>[30632.241590] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
> [<c03c06e8>] (netif_receive_skb+0x1c/0x90)
> <4>[30632.251240] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
> [<c03c2fac>] (napi_skb_finish+0x54/0x78)
> <4>[30632.260371] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
> [<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
> <4>[30632.269066] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
> [<c03c2758>] (net_rx_action+0x140/0x228)
> <4>[30632.277761] [<c03c2758>] (net_rx_action+0x140/0x228) from
> [<c002ac94>] (__do_softirq+0xb4/0x1cc)
> <4>[30632.286541] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
> [<c002b18c>] (irq_exit+0x80/0x88)
> <4>[30632.294716] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
> (handle_IRQ+0x50/0xb0)
> <4>[30632.302629] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
> (gic_handle_irq+0x24/0x58)
> <4>[30632.311062] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
> [<c049e100>] (__irq_svc+0x40/0x50)
> <4>[30632.319402] Exception stack(0xeca4dc10 to 0xeca4dc58)
> <4>[30632.324445] dc00:                                     c2f7a580
> 02000020 02000000 00000000
> <4>[30632.332615] dc20: c2f7a580 e9e4f33c e9e4f34c 00000000 ec185300
> 00001000 00000000 00001000
> <4>[30632.340783] dc40: 00000001 eca4dc58 c0136cbc c0136cd4 200f0013
> ffffffff
> <4>[30632.347398] [<c049e100>] (__irq_svc+0x40/0x50) from [<c0136cd4>]
> (__set_page_dirty+0x80/0xc0)
> <4>[30632.355919] [<c0136cd4>] (__set_page_dirty+0x80/0xc0) from
> [<c01387ac>] (__block_commit_write+0xb4/0xe0)
> <4>[30632.365394] [<c01387ac>] (__block_commit_write+0xb4/0xe0) from
> [<c0138eb4>] (block_write_end+0x4c/0x84)
> <4>[30632.374782] [<c0138eb4>] (block_write_end+0x4c/0x84) from
> [<c0138f20>] (generic_write_end+0x34/0xb0)
> <4>[30632.383911] [<c0138f20>] (generic_write_end+0x34/0xb0) from
> [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340)
> <4>[30632.393303] [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340) from
> [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x25
> 8)
> <4>[30632.403648] [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x258)
> from [<c00cb1d8>] (__generic_file_aio_write+0x
> 274/0x4bc)
> <4>[30632.414684] [<c00cb1d8>] (__generic_file_aio_write+0x274/0x4bc)
> from [<c00cb47c>] (generic_file_aio_write+0x5c/0
> xc8)
> <4>[30632.425201] [<c00cb47c>] (generic_file_aio_write+0x5c/0xc8) from
> [<c019810c>] (ext4_file_write+0xcc/0x2a0)
> <4>[30632.434853] [<c019810c>] (ext4_file_write+0xcc/0x2a0) from
> [<c010a950>] (do_sync_write+0xa8/0xe8)
> <4>[30632.443722] [<c010a950>] (do_sync_write+0xa8/0xe8) from
> [<c010b360>] (vfs_write+0x9c/0x170)
> <4>[30632.452069] [<c010b360>] (vfs_write+0x9c/0x170) from [<c010b648>]
> (sys_write+0x38/0x70)
> <4>[30632.460068] [<c010b648>] (sys_write+0x38/0x70) from [<c000db60>]
> (ret_fast_syscall+0x0/0x30)
> 
> The full stack looks like this:
> 
> include/linux/skbuff.h:__skb_unlink
> include/net/tcp.h:tcp_unlink_write_queue
> net/ipv4/tcp_input.c:tcp_clean_rtx_queue
> net/ipv4/tcp_input.c:tcp_ack
> 
> This panic is in __skb_unlink with the skb prev ptr being NULL. Here's
> the disassembly:
> 
>                 if (!fully_acked)
> c04070cc:       e3520000        cmp     r2, #0
> c04070d0:       0afffecb        beq     c0406c04 <tcp_ack+0x2ac>
> extern void        skb_unlink(struct sk_buff *skb, struct sk_buff_head
> *list);
> static inline void __skb_unlink(struct sk_buff *skb, struct sk_buff_head
> *list)
> {
>         struct sk_buff *next, *prev;
> 
>         list->qlen--;
> c04070d4:       e59430a8        ldr     r3, [r4, #168]  ; 0xa8
> static inline void sk_wmem_free_skb(struct sock *sk, struct sk_buff *skb)
> {
>         sock_set_flag(sk, SOCK_QUEUE_SHRUNK);
>         sk->sk_wmem_queued -= skb->truesize;
>         sk_mem_uncharge(sk, skb->truesize);
>         __kfree_skb(skb);
> c04070d8:       e1a00005        mov     r0, r5
> c04070dc:       e2433001        sub     r3, r3, #1
> c04070e0:       e58430a8        str     r3, [r4, #168]  ; 0xa8
>         next       = skb->next;
>         prev       = skb->prev;
> c04070e4:       e895000c        ldm     r5, {r2, r3}
>         skb->next  = skb->prev = NULL;
> c04070e8:       e5859000        str     r9, [r5]
> c04070ec:       e5859004        str     r9, [r5, #4]
>         next->prev = prev;
> c04070f0:       e5823004        str     r3, [r2, #4]
>         prev->next = next;
> c04070f4:       e5832000        str     r2, [r3]
> 
> Rob


This looks like random memory scribbling of NULL pointers to me.

I have never seen such a pattern. (I admit I do not use ARM machines as
much as you do :) )

Your best bet would be to perform a (reverse) bisection if you know
recent kernels are OK.

Re: panics in tcp_ack

[Rob Herring]

On 06/03/2013 08:25 AM, Eric Dumazet wrote:
> On Mon, 2013-06-03 at 08:05 -0500, Rob Herring wrote:
>> On 06/02/2013 09:23 PM, Rob Herring wrote:
>>> On 06/02/2013 07:36 PM, Eric Dumazet wrote:
>>>> On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
>>>>> Sorry, this time with proper line wrapping...
>>>>>
>>>>> I'm debugging a kernel panic in the networking stack that happens with a
>>>>> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
>>>>> typically only after 10-24 hours. The node are transferring files
>>>>> between nodes over TCP with 20 clients and servers per node. The kernel
>>>>> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
>>>>> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
>>>>> bisect have not yielded results as it seems multiple problems mask the
>>>>> issue. Perhaps there is some new feature which has indirectly fixed the
>>>>> problem in 3.8.
>>>>>
>>>>> This commit appears to fix a similar panic and seems to reduce the
>>>>> frequency after picking it up in the latest 3.5 stable:
>>>>>
>>>>> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
>>>>> Author: Eric Dumazet <edumazet@google.com>
>>>>> Date:   Thu Mar 14 05:40:32 2013 +0000
>>>>>
>>>>>     tcp: fix skb_availroom()
>>>>>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
>>>>>         https://code.google.com/p/chromium/issues/detail?id=182056
>>>>>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
>>>>>     path) did a poor choice adding an 'avail_size' field to skb, while
>>>>>     what we really needed was a 'reserved_tailroom' one.
>>>>>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
>>>>>     partially acked frames) and this commit.
>>>>>         Crash occurs because skb_split() is not aware of the 'avail_size'
>>>>>     management (and should not be aware)
>>>>>         Signed-off-by: Eric Dumazet <edumazet@google.com>
>>>>>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
>>>>>     Signed-off-by: David S. Miller <davem@davemloft.net>
>>>>>
>>>>> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
>>>>> relevant commits and applied these commits not in 3.5 stable. However,
>>>>> they have not helped:
>>>>>
>>>>> net: drop dst before queueing fragments
>>>>> tcp: call tcp_replace_ts_recent() from tcp_ack()
>>>>> tcp: Reallocate headroom if it would overflow csum_start
>>>>> tcp: incoming connections might use wrong route under synflood
>>>>>
>>>>
>>>> try also :
>>>>
>>>> commit 093162553c33e94 (tcp: force a dst refcount when prequeue packet)
>>>> commit 0d4f0608619de59 (tcp: dont handle MTU reduction on LISTEN socket)
>>>
>>> Will add and test.
>>>
>>>> commit 6731d2095bd4aef (tcp: fix for zero packets_in_flight was too
>>>> broad)
>>>> commit 2e5f421211ff76c (tcp: frto should not set snd_cwnd to 0)
>>>
>>> I have these 2.
>>
>> Ran overnight with the 2 additional patches. One panic after ~9 hours
>> running on 75 nodes.
>>
>> <4>[30632.185861] [<c04070f4>] (tcp_ack+0x79c/0x1014) from [<c0407cb4>]
>> (tcp_rcv_established+0x348/0x5e0)
>> <4>[30632.194903] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
>> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
>> <4>[30632.204291] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
>> [<c04111cc>] (tcp_v4_rcv+0x834/0x918)
>> <4>[30632.212900] [<c04111cc>] (tcp_v4_rcv+0x834/0x918) from
>> [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
>> <4>[30632.222376] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
>> [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
>> <4>[30632.232115] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
>> [<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
>> <4>[30632.241590] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
>> [<c03c06e8>] (netif_receive_skb+0x1c/0x90)
>> <4>[30632.251240] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
>> [<c03c2fac>] (napi_skb_finish+0x54/0x78)
>> <4>[30632.260371] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
>> [<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
>> <4>[30632.269066] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
>> [<c03c2758>] (net_rx_action+0x140/0x228)
>> <4>[30632.277761] [<c03c2758>] (net_rx_action+0x140/0x228) from
>> [<c002ac94>] (__do_softirq+0xb4/0x1cc)
>> <4>[30632.286541] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
>> [<c002b18c>] (irq_exit+0x80/0x88)
>> <4>[30632.294716] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
>> (handle_IRQ+0x50/0xb0)
>> <4>[30632.302629] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
>> (gic_handle_irq+0x24/0x58)
>> <4>[30632.311062] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
>> [<c049e100>] (__irq_svc+0x40/0x50)
>> <4>[30632.319402] Exception stack(0xeca4dc10 to 0xeca4dc58)
>> <4>[30632.324445] dc00:                                     c2f7a580
>> 02000020 02000000 00000000
>> <4>[30632.332615] dc20: c2f7a580 e9e4f33c e9e4f34c 00000000 ec185300
>> 00001000 00000000 00001000
>> <4>[30632.340783] dc40: 00000001 eca4dc58 c0136cbc c0136cd4 200f0013
>> ffffffff
>> <4>[30632.347398] [<c049e100>] (__irq_svc+0x40/0x50) from [<c0136cd4>]
>> (__set_page_dirty+0x80/0xc0)
>> <4>[30632.355919] [<c0136cd4>] (__set_page_dirty+0x80/0xc0) from
>> [<c01387ac>] (__block_commit_write+0xb4/0xe0)
>> <4>[30632.365394] [<c01387ac>] (__block_commit_write+0xb4/0xe0) from
>> [<c0138eb4>] (block_write_end+0x4c/0x84)
>> <4>[30632.374782] [<c0138eb4>] (block_write_end+0x4c/0x84) from
>> [<c0138f20>] (generic_write_end+0x34/0xb0)
>> <4>[30632.383911] [<c0138f20>] (generic_write_end+0x34/0xb0) from
>> [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340)
>> <4>[30632.393303] [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340) from
>> [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x25
>> 8)
>> <4>[30632.403648] [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x258)
>> from [<c00cb1d8>] (__generic_file_aio_write+0x
>> 274/0x4bc)
>> <4>[30632.414684] [<c00cb1d8>] (__generic_file_aio_write+0x274/0x4bc)
>> from [<c00cb47c>] (generic_file_aio_write+0x5c/0
>> xc8)
>> <4>[30632.425201] [<c00cb47c>] (generic_file_aio_write+0x5c/0xc8) from
>> [<c019810c>] (ext4_file_write+0xcc/0x2a0)
>> <4>[30632.434853] [<c019810c>] (ext4_file_write+0xcc/0x2a0) from
>> [<c010a950>] (do_sync_write+0xa8/0xe8)
>> <4>[30632.443722] [<c010a950>] (do_sync_write+0xa8/0xe8) from
>> [<c010b360>] (vfs_write+0x9c/0x170)
>> <4>[30632.452069] [<c010b360>] (vfs_write+0x9c/0x170) from [<c010b648>]
>> (sys_write+0x38/0x70)
>> <4>[30632.460068] [<c010b648>] (sys_write+0x38/0x70) from [<c000db60>]
>> (ret_fast_syscall+0x0/0x30)
>>
>> The full stack looks like this:
>>
>> include/linux/skbuff.h:__skb_unlink
>> include/net/tcp.h:tcp_unlink_write_queue
>> net/ipv4/tcp_input.c:tcp_clean_rtx_queue
>> net/ipv4/tcp_input.c:tcp_ack
>>
>> This panic is in __skb_unlink with the skb prev ptr being NULL. Here's
>> the disassembly:
>>
>>                 if (!fully_acked)
>> c04070cc:       e3520000        cmp     r2, #0
>> c04070d0:       0afffecb        beq     c0406c04 <tcp_ack+0x2ac>
>> extern void        skb_unlink(struct sk_buff *skb, struct sk_buff_head
>> *list);
>> static inline void __skb_unlink(struct sk_buff *skb, struct sk_buff_head
>> *list)
>> {
>>         struct sk_buff *next, *prev;
>>
>>         list->qlen--;
>> c04070d4:       e59430a8        ldr     r3, [r4, #168]  ; 0xa8
>> static inline void sk_wmem_free_skb(struct sock *sk, struct sk_buff *skb)
>> {
>>         sock_set_flag(sk, SOCK_QUEUE_SHRUNK);
>>         sk->sk_wmem_queued -= skb->truesize;
>>         sk_mem_uncharge(sk, skb->truesize);
>>         __kfree_skb(skb);
>> c04070d8:       e1a00005        mov     r0, r5
>> c04070dc:       e2433001        sub     r3, r3, #1
>> c04070e0:       e58430a8        str     r3, [r4, #168]  ; 0xa8
>>         next       = skb->next;
>>         prev       = skb->prev;
>> c04070e4:       e895000c        ldm     r5, {r2, r3}
>>         skb->next  = skb->prev = NULL;
>> c04070e8:       e5859000        str     r9, [r5]
>> c04070ec:       e5859004        str     r9, [r5, #4]
>>         next->prev = prev;
>> c04070f0:       e5823004        str     r3, [r2, #4]
>>         prev->next = next;
>> c04070f4:       e5832000        str     r2, [r3]
>>
>> Rob
> 
> 
> This looks like random memory scribbling of NULL pointers to me.
> 
> I have never seen such a pattern. (I admit I do not use ARM machines as
> much as you do :) )

Any ideas on what could cause that? Anything the driver could be doing
or not doing to cause it? Perhaps some memory ordering or visibility issue.

> Your best bet would be to perform a (reverse) bisection if you know
> recent kernels are OK.

I did that once looking at 3.6 and 3.7 stable kernels, but they did not
have fixes like "tcp: fix skb_availroom()" and so I just hit other
failures. I'll do it again with more fixes applied.

Rob

Re: panics in tcp_ack

[Eric Dumazet]

On Mon, 2013-06-03 at 10:51 -0500, Rob Herring wrote:

> Any ideas on what could cause that? Anything the driver could be doing
> or not doing to cause it? Perhaps some memory ordering or visibility issue.
> 

Yes, maybe, but I have no idea.

> > Your best bet would be to perform a (reverse) bisection if you know
> > recent kernels are OK.
> 
> I did that once looking at 3.6 and 3.7 stable kernels, but they did not
> have fixes like "tcp: fix skb_availroom()" and so I just hit other
> failures. I'll do it again with more fixes applied.

Yes, you'll have to apply a number of known fixes at every step of the
bisection, sorry !

Re: panics in tcp_ack

[Rob Herring]

Adding lakml and some ARM folks...

On Sun, Jun 2, 2013 at 7:16 PM, Rob Herring <robherring2@gmail.com> wrote:
> Sorry, this time with proper line wrapping...
>
> I'm debugging a kernel panic in the networking stack that happens with a
> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
> typically only after 10-24 hours. The node are transferring files
> between nodes over TCP with 20 clients and servers per node. The kernel
> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
> bisect have not yielded results as it seems multiple problems mask the
> issue. Perhaps there is some new feature which has indirectly fixed the
> problem in 3.8.

It turns out this issue is not fixed on 3.8. I've built a stable
3.8.13 kernel and still get the failure. There don't appear to be any
significant differences in commits between 3.8.13 and raring 3.8
kernel. The key difference appears to be the config and some key
differences are that various ARM errata work-arounds are enabled in
the raring kernel, but not my 3.8 config. Initial testing enabling the
work-arounds on the failing kernel and disabling them on the working
kernel seem to prove this theory.

However, none of the additional errata enabled in the raring kernel
need to be enabled based on the revs of the core (r3p0) and pl310
(r3p2). So it seems one of the work-arounds also fixes some different
issue. There are probably few other A9's out in production at this
revision, so everyone else runs with these work-arounds enabled and
would never see any issue uncovered by disabling them.

These are the additional errata enabled in the raring kernel:

Core
430973 - A8 errata. flushes BTAC on context switch
775420 - dsb at end of v7_coherent_kern_range/v7_coherent_user_range

PL310
588369 - does separate clean then invalidate op instead of
clean+invalidate operation
727915 - should be no diff on > r3p0 pl310
769419 - adds wmb (L2 drain) to idle

Rob

>
> This commit appears to fix a similar panic and seems to reduce the
> frequency after picking it up in the latest 3.5 stable:
>
> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
> Author: Eric Dumazet <edumazet@google.com>
> Date:   Thu Mar 14 05:40:32 2013 +0000
>
>     tcp: fix skb_availroom()
>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
>         https://code.google.com/p/chromium/issues/detail?id=182056
>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
>     path) did a poor choice adding an 'avail_size' field to skb, while
>     what we really needed was a 'reserved_tailroom' one.
>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
>     partially acked frames) and this commit.
>         Crash occurs because skb_split() is not aware of the 'avail_size'
>     management (and should not be aware)
>         Signed-off-by: Eric Dumazet <edumazet@google.com>
>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
>     Signed-off-by: David S. Miller <davem@davemloft.net>
>
> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
> relevant commits and applied these commits not in 3.5 stable. However,
> they have not helped:
>
> net: drop dst before queueing fragments
> tcp: call tcp_replace_ts_recent() from tcp_ack()
> tcp: Reallocate headroom if it would overflow csum_start
> tcp: incoming connections might use wrong route under synflood
>
>
> The exact panic varies some, but is typically in tcp_ack. I've gotten
> this one several times:
>
> <4>[17360.343983] [<c0405e08>] (tcp_fastretrans_alert+0x134/0xbec) from
> [<c0406e98>] (tcp_ack+0x540/0x1014)
> <4>[17360.353216] [<c0406e98>] (tcp_ack+0x540/0x1014) from [<c0407cb4>]
> (tcp_rcv_established+0x348/0x5e0)
> <4>[17360.362276] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
> <4>[17360.371679] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
> [<c04111ac>] (tcp_v4_rcv+0x814/0x8e8)
> <4>[17360.380307] [<c04111ac>] (tcp_v4_rcv+0x814/0x8e8) from
> [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
> <4>[17360.389796] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
> [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
> <4>[17360.399552] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
> [<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
> <4>[17360.409045] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
> [<c03c06e8>] (netif_receive_skb+0x1c/0x90)
> <4>[17360.418708] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
> [<c03c2fac>] (napi_skb_finish+0x54/0x78)
> <4>[17360.427855] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
> [<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
> <4>[17360.436567] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
> [<c03c2758>] (net_rx_action+0x140/0x228)
> <4>[17360.445280] [<c03c2758>] (net_rx_action+0x140/0x228) from
> [<c002ac94>] (__do_softirq+0xb4/0x1cc)
> <4>[17360.454078] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
> [<c002b18c>] (irq_exit+0x80/0x88)
> <4>[17360.462269] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
> (handle_IRQ+0x50/0xb0)
> <4>[17360.470197] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
> (gic_handle_irq+0x24/0x58)
> <4>[17360.478645] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
> [<c049e1fc>] (__irq_usr+0x3c/0x60)
> <4>[17360.486994] Exception stack(0xeda89fb0 to 0xeda89ff8)
> <4>[17360.492042] 9fa0:                                     b6e0c1cc
> 0000c004 00000000 0000001c
> <4>[17360.500217] 9fc0: 00000000 00000000 0000007c 0012d175 0012d174
> ffffffff 0012d175 b692caf0
> <4>[17360.508393] 9fe0: 001a3340 bead3758 0007bfab 0007bfb0 800f0030
> ffffffff
> <0>[17360.515011] Code: e595c2bc e1510000 e5960000 03a01000 (e5911038)
> <4>[17360.521207] ---[ end trace 98dabb30d5917f53 ]---
>
> This appears to be a NULL returned from tcp_write_queue_head. I
> reconstructed the full stack which looks like this:
>
> tcp_write_queue_head(sk) tcp_skb_timedout
> tcp_head_timedout
> tcp_time_to_recover
> tcp_fastretrans_alert
>
>
> Searching for similar panics I found this debug patch:
>
> http://www.spinics.net/lists/mm-commits/msg49089.html
>
> With the initial patch, I got continuous spewing of debug due to
> "fackets != tp->fackets_out", so I removed some of the checks and now
> just get these dumps. I'm not sure if there is anything relevant here
> and none of the warnings are triggered:
>
> [12622.995006] P: 28 L: 7 vs 7 S: 5 vs 5 F: 12 vs 12 w:
> 1697479957-1697494437 (5)
> [12623.002273] skb 0 def35f80
> [12623.004978] skb 1 def373c0
> [12623.007676] skb 2 def346c0
> [12623.010374] skb 3 e1b42400
> [12623.013092] skb 4 e1b40000
> [12623.015794] skb 5 e1b41680
> [12623.018490] skb 6 e1b418c0
> [12623.021190] skb 7 e1b42f40
> [12623.023908] skb 8 dec51680
> [12623.026608] skb 9 dec7b600
> [12623.029306] skb 10 e0505f80
> [12623.032105] skb 11 dec786c0
> [12623.034892] skb 12 dec7a880
> [12623.037676] skb 13 dec7b840
> [12623.040460] skb 14 dec78d80
> [12623.043263] skb 15 e0430900
> [12623.046050] skb 16 e0431440
> [12623.048835] skb 17 e04321c0
> [12623.051618] skb 18 e04318c0
> [12623.054422] skb 19 e0433a80
> [12623.057208] skb 20 e04333c0
> [12623.059991] skb 21 e0432640
> [12623.062792] head 22 e040df80
> [12623.065667] skb 23 e0542ac0
> [12623.068453] skb 24 e0431200
> [12623.071239] skb 25 e040f600
> [12623.074041] TCP wq(s) LLLLLLLSSSSS                <
> [12623.078910] TCP wq(h) ++++++++----++++++h+-++++++-<
> [12623.083792] l7 s5 f12 p28 seq: su1697479957 hs1697479957 sn1697494437
>
> [18018.368510] P: 24 L: 10 vs 10 S: 6 vs 6 F: 13 vs 13 w:
> 524404136-524415720 (7)
> [18018.375788] skb 0 e9742f40
> [18018.378495] skb 1 e9741d40
> [18018.381194] skb 2 e0473a80
> [18018.383915] skb 3 e0470fc0
> [18018.386621] skb 4 e0472f40
> [18018.389320] skb 5 e04706c0
> [18018.392035] skb 6 e0473180
> [18018.394736] skb 7 e054af40
> [18018.397435] skb 8 deeae400
> [18018.400133] skb 9 e19e86c0
> [18018.402854] skb 10 e19e98c0
> [18018.405643] skb 11 e0472880
> [18018.408429] skb 12 e19eaf40
> [18018.411216] head 13 e19eb180
> [18018.414116] skb 14 e055c000
> [18018.416913] TCP wq(s) LLLLLLLSSSSSSLLL        <
> [18018.421439] TCP wq(h) ++++++++-----+++h---+---<
> [18018.425999] l10 s6 f13 p24 seq: su524404136 hs524404136 sn524415720
>
> The current 3.5 tree I'm testing is available here:
>
> git://sources.calxeda.com/linux/kernel.git 3.5-net-debug
>
> Rob

Re: panics in tcp_ack

[Rob Herring]

On 06/03/2013 08:25 AM, Eric Dumazet wrote:
> On Mon, 2013-06-03 at 08:05 -0500, Rob Herring wrote:
>> On 06/02/2013 09:23 PM, Rob Herring wrote:
>>> On 06/02/2013 07:36 PM, Eric Dumazet wrote:
>>>> On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
>>>>> Sorry, this time with proper line wrapping...
>>>>>
>>>>> I'm debugging a kernel panic in the networking stack that happens with a
>>>>> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
>>>>> typically only after 10-24 hours. The node are transferring files
>>>>> between nodes over TCP with 20 clients and servers per node. The kernel
>>>>> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
>>>>> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
>>>>> bisect have not yielded results as it seems multiple problems mask the
>>>>> issue. Perhaps there is some new feature which has indirectly fixed the
>>>>> problem in 3.8.
>>>>>
>>>>> This commit appears to fix a similar panic and seems to reduce the
>>>>> frequency after picking it up in the latest 3.5 stable:
>>>>>
>>>>> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
>>>>> Author: Eric Dumazet <edumazet@google.com>
>>>>> Date:   Thu Mar 14 05:40:32 2013 +0000
>>>>>
>>>>>     tcp: fix skb_availroom()
>>>>>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
>>>>>         https://code.google.com/p/chromium/issues/detail?id=182056
>>>>>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
>>>>>     path) did a poor choice adding an 'avail_size' field to skb, while
>>>>>     what we really needed was a 'reserved_tailroom' one.
>>>>>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
>>>>>     partially acked frames) and this commit.
>>>>>         Crash occurs because skb_split() is not aware of the 'avail_size'
>>>>>     management (and should not be aware)
>>>>>         Signed-off-by: Eric Dumazet <edumazet@google.com>
>>>>>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
>>>>>     Signed-off-by: David S. Miller <davem@davemloft.net>
>>>>>
>>>>> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
>>>>> relevant commits and applied these commits not in 3.5 stable. However,
>>>>> they have not helped:
>>>>>
>>>>> net: drop dst before queueing fragments
>>>>> tcp: call tcp_replace_ts_recent() from tcp_ack()
>>>>> tcp: Reallocate headroom if it would overflow csum_start
>>>>> tcp: incoming connections might use wrong route under synflood
>>>>>
>>>>
>>>> try also :
>>>>
>>>> commit 093162553c33e94 (tcp: force a dst refcount when prequeue packet)
>>>> commit 0d4f0608619de59 (tcp: dont handle MTU reduction on LISTEN socket)
>>>
>>> Will add and test.
>>>
>>>> commit 6731d2095bd4aef (tcp: fix for zero packets_in_flight was too
>>>> broad)
>>>> commit 2e5f421211ff76c (tcp: frto should not set snd_cwnd to 0)
>>>
>>> I have these 2.
>>
>> Ran overnight with the 2 additional patches. One panic after ~9 hours
>> running on 75 nodes.
>>
>> <4>[30632.185861] [<c04070f4>] (tcp_ack+0x79c/0x1014) from [<c0407cb4>]
>> (tcp_rcv_established+0x348/0x5e0)
>> <4>[30632.194903] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
>> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
>> <4>[30632.204291] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
>> [<c04111cc>] (tcp_v4_rcv+0x834/0x918)
>> <4>[30632.212900] [<c04111cc>] (tcp_v4_rcv+0x834/0x918) from
>> [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
>> <4>[30632.222376] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
>> [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
>> <4>[30632.232115] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
>> [<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
>> <4>[30632.241590] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
>> [<c03c06e8>] (netif_receive_skb+0x1c/0x90)
>> <4>[30632.251240] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
>> [<c03c2fac>] (napi_skb_finish+0x54/0x78)
>> <4>[30632.260371] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
>> [<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
>> <4>[30632.269066] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
>> [<c03c2758>] (net_rx_action+0x140/0x228)
>> <4>[30632.277761] [<c03c2758>] (net_rx_action+0x140/0x228) from
>> [<c002ac94>] (__do_softirq+0xb4/0x1cc)
>> <4>[30632.286541] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
>> [<c002b18c>] (irq_exit+0x80/0x88)
>> <4>[30632.294716] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
>> (handle_IRQ+0x50/0xb0)
>> <4>[30632.302629] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
>> (gic_handle_irq+0x24/0x58)
>> <4>[30632.311062] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
>> [<c049e100>] (__irq_svc+0x40/0x50)
>> <4>[30632.319402] Exception stack(0xeca4dc10 to 0xeca4dc58)
>> <4>[30632.324445] dc00:                                     c2f7a580
>> 02000020 02000000 00000000
>> <4>[30632.332615] dc20: c2f7a580 e9e4f33c e9e4f34c 00000000 ec185300
>> 00001000 00000000 00001000
>> <4>[30632.340783] dc40: 00000001 eca4dc58 c0136cbc c0136cd4 200f0013
>> ffffffff
>> <4>[30632.347398] [<c049e100>] (__irq_svc+0x40/0x50) from [<c0136cd4>]
>> (__set_page_dirty+0x80/0xc0)
>> <4>[30632.355919] [<c0136cd4>] (__set_page_dirty+0x80/0xc0) from
>> [<c01387ac>] (__block_commit_write+0xb4/0xe0)
>> <4>[30632.365394] [<c01387ac>] (__block_commit_write+0xb4/0xe0) from
>> [<c0138eb4>] (block_write_end+0x4c/0x84)
>> <4>[30632.374782] [<c0138eb4>] (block_write_end+0x4c/0x84) from
>> [<c0138f20>] (generic_write_end+0x34/0xb0)
>> <4>[30632.383911] [<c0138f20>] (generic_write_end+0x34/0xb0) from
>> [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340)
>> <4>[30632.393303] [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340) from
>> [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x25
>> 8)
>> <4>[30632.403648] [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x258)
>> from [<c00cb1d8>] (__generic_file_aio_write+0x
>> 274/0x4bc)
>> <4>[30632.414684] [<c00cb1d8>] (__generic_file_aio_write+0x274/0x4bc)
>> from [<c00cb47c>] (generic_file_aio_write+0x5c/0
>> xc8)
>> <4>[30632.425201] [<c00cb47c>] (generic_file_aio_write+0x5c/0xc8) from
>> [<c019810c>] (ext4_file_write+0xcc/0x2a0)
>> <4>[30632.434853] [<c019810c>] (ext4_file_write+0xcc/0x2a0) from
>> [<c010a950>] (do_sync_write+0xa8/0xe8)
>> <4>[30632.443722] [<c010a950>] (do_sync_write+0xa8/0xe8) from
>> [<c010b360>] (vfs_write+0x9c/0x170)
>> <4>[30632.452069] [<c010b360>] (vfs_write+0x9c/0x170) from [<c010b648>]
>> (sys_write+0x38/0x70)
>> <4>[30632.460068] [<c010b648>] (sys_write+0x38/0x70) from [<c000db60>]
>> (ret_fast_syscall+0x0/0x30)
>>
>> The full stack looks like this:
>>
>> include/linux/skbuff.h:__skb_unlink
>> include/net/tcp.h:tcp_unlink_write_queue
>> net/ipv4/tcp_input.c:tcp_clean_rtx_queue
>> net/ipv4/tcp_input.c:tcp_ack
>>
>> This panic is in __skb_unlink with the skb prev ptr being NULL. Here's
>> the disassembly:
>>
>>                 if (!fully_acked)
>> c04070cc:       e3520000        cmp     r2, #0
>> c04070d0:       0afffecb        beq     c0406c04 <tcp_ack+0x2ac>
>> extern void        skb_unlink(struct sk_buff *skb, struct sk_buff_head
>> *list);
>> static inline void __skb_unlink(struct sk_buff *skb, struct sk_buff_head
>> *list)
>> {
>>         struct sk_buff *next, *prev;
>>
>>         list->qlen--;
>> c04070d4:       e59430a8        ldr     r3, [r4, #168]  ; 0xa8
>> static inline void sk_wmem_free_skb(struct sock *sk, struct sk_buff *skb)
>> {
>>         sock_set_flag(sk, SOCK_QUEUE_SHRUNK);
>>         sk->sk_wmem_queued -= skb->truesize;
>>         sk_mem_uncharge(sk, skb->truesize);
>>         __kfree_skb(skb);
>> c04070d8:       e1a00005        mov     r0, r5
>> c04070dc:       e2433001        sub     r3, r3, #1
>> c04070e0:       e58430a8        str     r3, [r4, #168]  ; 0xa8
>>         next       = skb->next;
>>         prev       = skb->prev;
>> c04070e4:       e895000c        ldm     r5, {r2, r3}
>>         skb->next  = skb->prev = NULL;
>> c04070e8:       e5859000        str     r9, [r5]
>> c04070ec:       e5859004        str     r9, [r5, #4]
>>         next->prev = prev;
>> c04070f0:       e5823004        str     r3, [r2, #4]
>>         prev->next = next;
>> c04070f4:       e5832000        str     r2, [r3]
>>
>> Rob
> 
> 
> This looks like random memory scribbling of NULL pointers to me.
> 
> I have never seen such a pattern. (I admit I do not use ARM machines as
> much as you do :) )
> 
> Your best bet would be to perform a (reverse) bisection if you know
> recent kernels are OK.

We've been able to get kgdb working for this and found some additional
info. We first load the next and prev ptrs into r2 and r3 from the skb:

   0xc0407340 <+1932>:	ldm	r5, {r2, r3}

Then in kgdb, we get these values for r2 and r3:

r2             0xca6c3200
r3             0x0

But, if we go read the skb in kgdb, both pointers are NULL:

(gdb) p *skb
$3 = {next = 0x0, prev = 0x0, tstamp = {tv64 = 1371139692889955006}, sk
= 0x0, dev = 0x0,
  cb = '\000' <repeats 24 times>,
"X\244\021\027\000\252\021\027\226Ts\000\020\000\000\000\000\000\000\000\000\000\000",
_skb_refdst = 0, sp = 0x0, len = 1448, data_len = 1448, mac_len = 0,
  hdr_len = 0, {csum = 0, {csum_start = 0, csum_offset = 0}}, priority =
0, local_df = 0 '\000',
  cloned = 1 '\001', ip_summed = 3 '\003', nohdr = 1 '\001', nfctinfo =
0 '\000',
  pkt_type = 0 '\000', fclone = 1 '\001', ipvs_property = 0 '\000',
peeked = 0 '\000',
  nf_trace = 0 '\000', protocol = 0, destructor = 0x0, nfct = 0x0,
nfct_reasm = 0x0,
  nf_bridge = 0x0, skb_iif = 0, rxhash = 0, vlan_tci = 0, tc_index = 0,
tc_verd = 0,
  queue_mapping = 0, ndisc_nodetype = 0 '\000', ooo_okay = 0 '\000',
l4_rxhash = 0 '\000',
  wifi_acked_valid = 0 '\000', wifi_acked = 0 '\000', no_fcs = 0 '\000',
head_frag = 0 '\000',
  secmark = 0, {mark = 48, dropcount = 48, reserved_tailroom = 48},
transport_header = 0x0,
  network_header = 0x0, mac_header = 0x0,
  tail = 0xea286b10 "eachpeachpeachpeachpeachpeachpea\300\254\205",
<incomplete sequence \302>,
  end = 0xea286b40 "\001", head = 0xea286a00 "",
  data = 0xea286b10 "eachpeachpeachpeachpeachpeachpea\300\254\205",
<incomplete sequence \302>,
  truesize = 2152, users = {counter = 1}}

This doesn't seem like random scribbling, but some ordering issue.

Anything else look suspect in the skb?

What lock should be held at this point?

Rob

Re: panics in tcp_ack

[Eric Dumazet]

On Fri, 2013-06-14 at 14:12 -0500, Rob Herring wrote:
> On 06/03/2013 08:25 AM, Eric Dumazet wrote:
> > On Mon, 2013-06-03 at 08:05 -0500, Rob Herring wrote:
> >> On 06/02/2013 09:23 PM, Rob Herring wrote:
> >>> On 06/02/2013 07:36 PM, Eric Dumazet wrote:
> >>>> On Sun, 2013-06-02 at 19:16 -0500, Rob Herring wrote:
> >>>>> Sorry, this time with proper line wrapping...
> >>>>>
> >>>>> I'm debugging a kernel panic in the networking stack that happens with a
> >>>>> cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and
> >>>>> typically only after 10-24 hours. The node are transferring files
> >>>>> between nodes over TCP with 20 clients and servers per node. The kernel
> >>>>> is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing
> >>>>> has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to
> >>>>> bisect have not yielded results as it seems multiple problems mask the
> >>>>> issue. Perhaps there is some new feature which has indirectly fixed the
> >>>>> problem in 3.8.
> >>>>>
> >>>>> This commit appears to fix a similar panic and seems to reduce the
> >>>>> frequency after picking it up in the latest 3.5 stable:
> >>>>>
> >>>>> commit 16fad69cfe4adbbfa813de516757b87bcae36d93
> >>>>> Author: Eric Dumazet <edumazet@google.com>
> >>>>> Date:   Thu Mar 14 05:40:32 2013 +0000
> >>>>>
> >>>>>     tcp: fix skb_availroom()
> >>>>>         Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
> >>>>>         https://code.google.com/p/chromium/issues/detail?id=182056
> >>>>>         commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
> >>>>>     path) did a poor choice adding an 'avail_size' field to skb, while
> >>>>>     what we really needed was a 'reserved_tailroom' one.
> >>>>>         It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
> >>>>>     partially acked frames) and this commit.
> >>>>>         Crash occurs because skb_split() is not aware of the 'avail_size'
> >>>>>     management (and should not be aware)
> >>>>>         Signed-off-by: Eric Dumazet <edumazet@google.com>
> >>>>>     Reported-by: Mukesh Agrawal <quiche@chromium.org>
> >>>>>     Signed-off-by: David S. Miller <davem@davemloft.net>
> >>>>>
> >>>>> I've searched thru 3.8 and 3.9 stable fixes looking for possibly
> >>>>> relevant commits and applied these commits not in 3.5 stable. However,
> >>>>> they have not helped:
> >>>>>
> >>>>> net: drop dst before queueing fragments
> >>>>> tcp: call tcp_replace_ts_recent() from tcp_ack()
> >>>>> tcp: Reallocate headroom if it would overflow csum_start
> >>>>> tcp: incoming connections might use wrong route under synflood
> >>>>>
> >>>>
> >>>> try also :
> >>>>
> >>>> commit 093162553c33e94 (tcp: force a dst refcount when prequeue packet)
> >>>> commit 0d4f0608619de59 (tcp: dont handle MTU reduction on LISTEN socket)
> >>>
> >>> Will add and test.
> >>>
> >>>> commit 6731d2095bd4aef (tcp: fix for zero packets_in_flight was too
> >>>> broad)
> >>>> commit 2e5f421211ff76c (tcp: frto should not set snd_cwnd to 0)
> >>>
> >>> I have these 2.
> >>
> >> Ran overnight with the 2 additional patches. One panic after ~9 hours
> >> running on 75 nodes.
> >>
> >> <4>[30632.185861] [<c04070f4>] (tcp_ack+0x79c/0x1014) from [<c0407cb4>]
> >> (tcp_rcv_established+0x348/0x5e0)
> >> <4>[30632.194903] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from
> >> [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
> >> <4>[30632.204291] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from
> >> [<c04111cc>] (tcp_v4_rcv+0x834/0x918)
> >> <4>[30632.212900] [<c04111cc>] (tcp_v4_rcv+0x834/0x918) from
> >> [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
> >> <4>[30632.222376] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from
> >> [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
> >> <4>[30632.232115] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from
> >> [<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
> >> <4>[30632.241590] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from
> >> [<c03c06e8>] (netif_receive_skb+0x1c/0x90)
> >> <4>[30632.251240] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from
> >> [<c03c2fac>] (napi_skb_finish+0x54/0x78)
> >> <4>[30632.260371] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from
> >> [<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
> >> <4>[30632.269066] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from
> >> [<c03c2758>] (net_rx_action+0x140/0x228)
> >> <4>[30632.277761] [<c03c2758>] (net_rx_action+0x140/0x228) from
> >> [<c002ac94>] (__do_softirq+0xb4/0x1cc)
> >> <4>[30632.286541] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from
> >> [<c002b18c>] (irq_exit+0x80/0x88)
> >> <4>[30632.294716] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>]
> >> (handle_IRQ+0x50/0xb0)
> >> <4>[30632.302629] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>]
> >> (gic_handle_irq+0x24/0x58)
> >> <4>[30632.311062] [<c00084d4>] (gic_handle_irq+0x24/0x58) from
> >> [<c049e100>] (__irq_svc+0x40/0x50)
> >> <4>[30632.319402] Exception stack(0xeca4dc10 to 0xeca4dc58)
> >> <4>[30632.324445] dc00:                                     c2f7a580
> >> 02000020 02000000 00000000
> >> <4>[30632.332615] dc20: c2f7a580 e9e4f33c e9e4f34c 00000000 ec185300
> >> 00001000 00000000 00001000
> >> <4>[30632.340783] dc40: 00000001 eca4dc58 c0136cbc c0136cd4 200f0013
> >> ffffffff
> >> <4>[30632.347398] [<c049e100>] (__irq_svc+0x40/0x50) from [<c0136cd4>]
> >> (__set_page_dirty+0x80/0xc0)
> >> <4>[30632.355919] [<c0136cd4>] (__set_page_dirty+0x80/0xc0) from
> >> [<c01387ac>] (__block_commit_write+0xb4/0xe0)
> >> <4>[30632.365394] [<c01387ac>] (__block_commit_write+0xb4/0xe0) from
> >> [<c0138eb4>] (block_write_end+0x4c/0x84)
> >> <4>[30632.374782] [<c0138eb4>] (block_write_end+0x4c/0x84) from
> >> [<c0138f20>] (generic_write_end+0x34/0xb0)
> >> <4>[30632.383911] [<c0138f20>] (generic_write_end+0x34/0xb0) from
> >> [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340)
> >> <4>[30632.393303] [<c01a0b8c>] (ext4_da_write_end+0xa4/0x340) from
> >> [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x25
> >> 8)
> >> <4>[30632.403648] [<c00ca2bc>] (generic_file_buffered_write+0xe0/0x258)
> >> from [<c00cb1d8>] (__generic_file_aio_write+0x
> >> 274/0x4bc)
> >> <4>[30632.414684] [<c00cb1d8>] (__generic_file_aio_write+0x274/0x4bc)
> >> from [<c00cb47c>] (generic_file_aio_write+0x5c/0
> >> xc8)
> >> <4>[30632.425201] [<c00cb47c>] (generic_file_aio_write+0x5c/0xc8) from
> >> [<c019810c>] (ext4_file_write+0xcc/0x2a0)
> >> <4>[30632.434853] [<c019810c>] (ext4_file_write+0xcc/0x2a0) from
> >> [<c010a950>] (do_sync_write+0xa8/0xe8)
> >> <4>[30632.443722] [<c010a950>] (do_sync_write+0xa8/0xe8) from
> >> [<c010b360>] (vfs_write+0x9c/0x170)
> >> <4>[30632.452069] [<c010b360>] (vfs_write+0x9c/0x170) from [<c010b648>]
> >> (sys_write+0x38/0x70)
> >> <4>[30632.460068] [<c010b648>] (sys_write+0x38/0x70) from [<c000db60>]
> >> (ret_fast_syscall+0x0/0x30)
> >>
> >> The full stack looks like this:
> >>
> >> include/linux/skbuff.h:__skb_unlink
> >> include/net/tcp.h:tcp_unlink_write_queue
> >> net/ipv4/tcp_input.c:tcp_clean_rtx_queue
> >> net/ipv4/tcp_input.c:tcp_ack
> >>
> >> This panic is in __skb_unlink with the skb prev ptr being NULL. Here's
> >> the disassembly:
> >>
> >>                 if (!fully_acked)
> >> c04070cc:       e3520000        cmp     r2, #0
> >> c04070d0:       0afffecb        beq     c0406c04 <tcp_ack+0x2ac>
> >> extern void        skb_unlink(struct sk_buff *skb, struct sk_buff_head
> >> *list);
> >> static inline void __skb_unlink(struct sk_buff *skb, struct sk_buff_head
> >> *list)
> >> {
> >>         struct sk_buff *next, *prev;
> >>
> >>         list->qlen--;
> >> c04070d4:       e59430a8        ldr     r3, [r4, #168]  ; 0xa8
> >> static inline void sk_wmem_free_skb(struct sock *sk, struct sk_buff *skb)
> >> {
> >>         sock_set_flag(sk, SOCK_QUEUE_SHRUNK);
> >>         sk->sk_wmem_queued -= skb->truesize;
> >>         sk_mem_uncharge(sk, skb->truesize);
> >>         __kfree_skb(skb);
> >> c04070d8:       e1a00005        mov     r0, r5
> >> c04070dc:       e2433001        sub     r3, r3, #1
> >> c04070e0:       e58430a8        str     r3, [r4, #168]  ; 0xa8
> >>         next       = skb->next;
> >>         prev       = skb->prev;
> >> c04070e4:       e895000c        ldm     r5, {r2, r3}
> >>         skb->next  = skb->prev = NULL;
> >> c04070e8:       e5859000        str     r9, [r5]
> >> c04070ec:       e5859004        str     r9, [r5, #4]
> >>         next->prev = prev;
> >> c04070f0:       e5823004        str     r3, [r2, #4]
> >>         prev->next = next;
> >> c04070f4:       e5832000        str     r2, [r3]
> >>
> >> Rob
> > 
> > 
> > This looks like random memory scribbling of NULL pointers to me.
> > 
> > I have never seen such a pattern. (I admit I do not use ARM machines as
> > much as you do :) )
> > 
> > Your best bet would be to perform a (reverse) bisection if you know
> > recent kernels are OK.
> 
> We've been able to get kgdb working for this and found some additional
> info. We first load the next and prev ptrs into r2 and r3 from the skb:
> 
>    0xc0407340 <+1932>:	ldm	r5, {r2, r3}
> 
> Then in kgdb, we get these values for r2 and r3:
> 
> r2             0xca6c3200
> r3             0x0
> 
> But, if we go read the skb in kgdb, both pointers are NULL:
> 
> (gdb) p *skb
> $3 = {next = 0x0, prev = 0x0, tstamp = {tv64 = 1371139692889955006}, sk
> = 0x0, dev = 0x0,
>   cb = '\000' <repeats 24 times>,
> "X\244\021\027\000\252\021\027\226Ts\000\020\000\000\000\000\000\000\000\000\000\000",
> _skb_refdst = 0, sp = 0x0, len = 1448, data_len = 1448, mac_len = 0,
>   hdr_len = 0, {csum = 0, {csum_start = 0, csum_offset = 0}}, priority =
> 0, local_df = 0 '\000',
>   cloned = 1 '\001', ip_summed = 3 '\003', nohdr = 1 '\001', nfctinfo =
> 0 '\000',
>   pkt_type = 0 '\000', fclone = 1 '\001', ipvs_property = 0 '\000',
> peeked = 0 '\000',
>   nf_trace = 0 '\000', protocol = 0, destructor = 0x0, nfct = 0x0,
> nfct_reasm = 0x0,
>   nf_bridge = 0x0, skb_iif = 0, rxhash = 0, vlan_tci = 0, tc_index = 0,
> tc_verd = 0,
>   queue_mapping = 0, ndisc_nodetype = 0 '\000', ooo_okay = 0 '\000',
> l4_rxhash = 0 '\000',
>   wifi_acked_valid = 0 '\000', wifi_acked = 0 '\000', no_fcs = 0 '\000',
> head_frag = 0 '\000',
>   secmark = 0, {mark = 48, dropcount = 48, reserved_tailroom = 48},
> transport_header = 0x0,
>   network_header = 0x0, mac_header = 0x0,
>   tail = 0xea286b10 "eachpeachpeachpeachpeachpeachpea\300\254\205",
> <incomplete sequence \302>,
>   end = 0xea286b40 "\001", head = 0xea286a00 "",
>   data = 0xea286b10 "eachpeachpeachpeachpeachpeachpea\300\254\205",
> <incomplete sequence \302>,
>   truesize = 2152, users = {counter = 1}}
> 
> This doesn't seem like random scribbling, but some ordering issue.
> 

I see nothing wrong, as __skb_unlink() clears skb->next and skb->prev

crash happens a bit later :

prev->next = next;


> Anything else look suspect in the skb?

Not really.

Only problem is skb->prev was NULL

> 
> What lock should be held at this point?
> 

The socket lock

panics in tcp_ack

[Rob Herring]

I'm debugging a kernel panic in the networking stack that happens with a cluster (20-40 nodes) of Calxeda highbank (ARM Cortex A9) nodes and typically only after 10-24 hours. The node are transferring files between nodes over TCP with 20 clients and servers per node. The kernel is based on ubuntu 3.5 kernel which is based on 3.5.7.11. So far testing has shown that 3.8.11 based (ubuntu raring) kernel is fixed. Attempts to bisect have not yielded results as it seems multiple problems mask the issue. Perhaps there is some new feature which has indirectly fixed the problem in 3.8.

This commit appears to fix a similar panic and seems to reduce the frequency after picking it up in the latest 3.5 stable:

commit 16fad69cfe4adbbfa813de516757b87bcae36d93
Author: Eric Dumazet <edumazet@google.com>
Date:   Thu Mar 14 05:40:32 2013 +0000

    tcp: fix skb_availroom()
    
    Chrome OS team reported a crash on a Pixel ChromeBook in TCP stack :
    
    https://code.google.com/p/chromium/issues/detail?id=182056
    
    commit a21d45726acac (tcp: avoid order-1 allocations on wifi and tx
    path) did a poor choice adding an 'avail_size' field to skb, while
    what we really needed was a 'reserved_tailroom' one.
    
    It would have avoided commit 22b4a4f22da (tcp: fix retransmit of
    partially acked frames) and this commit.
    
    Crash occurs because skb_split() is not aware of the 'avail_size'
    management (and should not be aware)
    
    Signed-off-by: Eric Dumazet <edumazet@google.com>
    Reported-by: Mukesh Agrawal <quiche@chromium.org>
    Signed-off-by: David S. Miller <davem@davemloft.net>

I've searched thru 3.8 and 3.9 stable fixes looking for possibly relevant commits and applied these commits not in 3.5 stable. However, they have not helped:

net: drop dst before queueing fragments
tcp: call tcp_replace_ts_recent() from tcp_ack()
tcp: Reallocate headroom if it would overflow csum_start
tcp: incoming connections might use wrong route under synflood


The exact panic varies some, but is typically in tcp_ack. I've gotten this one several times:

<4>[17360.343983] [<c0405e08>] (tcp_fastretrans_alert+0x134/0xbec) from [<c0406e98>] (tcp_ack+0x540/0x1014)
<4>[17360.353216] [<c0406e98>] (tcp_ack+0x540/0x1014) from [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0)
<4>[17360.362276] [<c0407cb4>] (tcp_rcv_established+0x348/0x5e0) from [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc)
<4>[17360.371679] [<c040eda8>] (tcp_v4_do_rcv+0xf0/0x2cc) from [<c04111ac>] (tcp_v4_rcv+0x814/0x8e8)
<4>[17360.380307] [<c04111ac>] (tcp_v4_rcv+0x814/0x8e8) from [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c)
<4>[17360.389796] [<c03ef81c>] (ip_local_deliver_finish+0xe8/0x33c) from [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0)
<4>[17360.399552] [<c03ef3b4>] (ip_rcv_finish+0x140/0x4c0) from [<c03bf944>] (__netif_receive_skb+0x5e0/0x690)
<4>[17360.409045] [<c03bf944>] (__netif_receive_skb+0x5e0/0x690) from [<c03c06e8>] (netif_receive_skb+0x1c/0x90)
<4>[17360.418708] [<c03c06e8>] (netif_receive_skb+0x1c/0x90) from [<c03c2fac>] (napi_skb_finish+0x54/0x78)
<4>[17360.427855] [<c03c2fac>] (napi_skb_finish+0x54/0x78) from [<c03301e4>] (xgmac_poll+0x3ac/0x4ec)
<4>[17360.436567] [<c03301e4>] (xgmac_poll+0x3ac/0x4ec) from [<c03c2758>] (net_rx_action+0x140/0x228)
<4>[17360.445280] [<c03c2758>] (net_rx_action+0x140/0x228) from [<c002ac94>] (__do_softirq+0xb4/0x1cc)
<4>[17360.454078] [<c002ac94>] (__do_softirq+0xb4/0x1cc) from [<c002b18c>] (irq_exit+0x80/0x88)
<4>[17360.462269] [<c002b18c>] (irq_exit+0x80/0x88) from [<c000ea7c>] (handle_IRQ+0x50/0xb0)
<4>[17360.470197] [<c000ea7c>] (handle_IRQ+0x50/0xb0) from [<c00084d4>] (gic_handle_irq+0x24/0x58)
<4>[17360.478645] [<c00084d4>] (gic_handle_irq+0x24/0x58) from [<c049e1fc>] (__irq_usr+0x3c/0x60)
<4>[17360.486994] Exception stack(0xeda89fb0 to 0xeda89ff8)
<4>[17360.492042] 9fa0:                                     b6e0c1cc 0000c004 00000000 0000001c
<4>[17360.500217] 9fc0: 00000000 00000000 0000007c 0012d175 0012d174 ffffffff 0012d175 b692caf0
<4>[17360.508393] 9fe0: 001a3340 bead3758 0007bfab 0007bfb0 800f0030 ffffffff
<0>[17360.515011] Code: e595c2bc e1510000 e5960000 03a01000 (e5911038) 
<4>[17360.521207] ---[ end trace 98dabb30d5917f53 ]---

This appears to be a NULL returned from tcp_write_queue_head. I reconstructed the full stack which looks like this:

tcp_write_queue_head(sk) 
tcp_skb_timedout
tcp_head_timedout
tcp_time_to_recover
tcp_fastretrans_alert


Searching for similar panics I found this debug patch:

http://www.spinics.net/lists/mm-commits/msg49089.html

With the initial patch, I got continuous spewing of debug due to "fackets != tp->fackets_out", so I removed some of the checks and now just get these dumps. I'm not sure if there is anything relevant here and none of the warnings are triggered:

[12622.995006] P: 28 L: 7 vs 7 S: 5 vs 5 F: 12 vs 12 w: 1697479957-1697494437 (5)
[12623.002273] skb 0 def35f80
[12623.004978] skb 1 def373c0
[12623.007676] skb 2 def346c0
[12623.010374] skb 3 e1b42400
[12623.013092] skb 4 e1b40000
[12623.015794] skb 5 e1b41680
[12623.018490] skb 6 e1b418c0
[12623.021190] skb 7 e1b42f40
[12623.023908] skb 8 dec51680
[12623.026608] skb 9 dec7b600
[12623.029306] skb 10 e0505f80
[12623.032105] skb 11 dec786c0
[12623.034892] skb 12 dec7a880
[12623.037676] skb 13 dec7b840
[12623.040460] skb 14 dec78d80
[12623.043263] skb 15 e0430900
[12623.046050] skb 16 e0431440
[12623.048835] skb 17 e04321c0
[12623.051618] skb 18 e04318c0
[12623.054422] skb 19 e0433a80
[12623.057208] skb 20 e04333c0
[12623.059991] skb 21 e0432640
[12623.062792] head 22 e040df80
[12623.065667] skb 23 e0542ac0
[12623.068453] skb 24 e0431200
[12623.071239] skb 25 e040f600
[12623.074041] TCP wq(s) LLLLLLLSSSSS                <
[12623.078910] TCP wq(h) ++++++++----++++++h+-++++++-<
[12623.083792] l7 s5 f12 p28 seq: su1697479957 hs1697479957 sn1697494437

[18018.368510] P: 24 L: 10 vs 10 S: 6 vs 6 F: 13 vs 13 w: 524404136-524415720 (7)
[18018.375788] skb 0 e9742f40
[18018.378495] skb 1 e9741d40
[18018.381194] skb 2 e0473a80
[18018.383915] skb 3 e0470fc0
[18018.386621] skb 4 e0472f40
[18018.389320] skb 5 e04706c0
[18018.392035] skb 6 e0473180
[18018.394736] skb 7 e054af40
[18018.397435] skb 8 deeae400
[18018.400133] skb 9 e19e86c0
[18018.402854] skb 10 e19e98c0
[18018.405643] skb 11 e0472880
[18018.408429] skb 12 e19eaf40
[18018.411216] head 13 e19eb180
[18018.414116] skb 14 e055c000
[18018.416913] TCP wq(s) LLLLLLLSSSSSSLLL        <
[18018.421439] TCP wq(h) ++++++++-----+++h---+---<
[18018.425999] l10 s6 f13 p24 seq: su524404136 hs524404136 sn524415720

The current 3.5 tree I'm testing is available here:

git://sources.calxeda.com/linux/kernel.git 3.5-net-debug

Rob