"kernel NULL pointer dereference" with sustained network traffic

[yann-morin-1998]

Using kernel rpi-3.6.y as of cset 245f716, I get repeatable kernel panics due to the kernel being "Unable to handle kernel NULL pointer dereference at virtual address 0000000d" :

[   39.133751] Unable to handle kernel NULL pointer dereference at virtual address 0000000d
[   39.145991] pgd = c5c54000
[   39.152605] [0000000d] *pgd=05c4e831, *pte=00000000, *ppte=00000000
[   39.162959] Internal error: Oops: 17 [#1] PREEMPT ARM
[   39.171808] Modules linked in: smsc95xx usbnet mii nls_utf8 nls_cp850 vfat fat
[   39.182955] CPU: 0    Not tainted  (3.6.11-yem #2)
[   39.191517] PC is at tcp_v4_early_demux+0xa8/0x148
[   39.200104] LR is at __inet_lookup_established+0x264/0x2e4
[   39.209357] pc : [<c026ace8>]    lr : [<c0251b60>]    psr: a0000113
[   39.209357] sp : c5c53b50  ip : c5c53b18  fp : c5c53b7c
[   39.228344] r10: c5c52030  r9 : c037ebcc  r8 : c5fb9280
[   39.237349] r7 : 00000000  r6 : 00000034  r5 : ffffffff  r4 : c5fb9280
[   39.247656] r3 : c021c9d0  r2 : c5c53b00  r1 : c0ff8ac0  r0 : ffffffff
[   39.257968] Flags: NzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
[   39.268928] Control: 00c5387d  Table: 05c54008  DAC: 00000015
[   39.278498] Process httpd (pid: 132, stack limit = 0xc5c52268)
[   39.288161] Stack: (0xc5c53b50 to 0xc5c54000)
[   39.296328] 3b40:                                     a77fa8c0 00000050 00000002 c0016c78
[   39.308363] 3b60: 00000022 c5838036 c5fb9298 0000e8ee c5c53bac c5c53b80 c0249e5c c026ac4c
[   39.320373] 3b80: c5c53bb4 c5c53b90 c03665b0 00000008 c69b0000 00000000 c5fb9280 c03665d4
[   39.332339] 3ba0: c5c53c04 c5c53bb0 c0229254 c0249b60 c0013744 c0013648 00400040 c5c52030
[   39.344270] 3bc0: c0d143e0 c69b0434 c5c53bec c5fb9280 c0262bc8 c03665d4 00000000 c03821e0
[   39.356172] 3be0: c03821b4 00000001 c03821d4 00000000 00100100 00000000 c5c53c34 c5c53c08
[   39.368099] 3c00: c02294a4 c0228e20 c036c3a8 c0229430 c03821e0 00000040 0000012c c03821a0
[   39.380034] 3c20: ffff9a0d c03821a8 c5c53c6c c5c53c38 c022b714 c022943c c0583800 c036c3a8
[   39.392007] 3c40: c5c53c6c 00000001 0000000c c0583830 c0583820 c5c52000 00000101 00000003
[   39.404042] 3c60: c5c53cb4 c5c53c70 c00237a8 c022b684 c5c53c8c c5c53c80 c0017734 00400040
[   39.416059] 3c80: c5c52030 00000008 c005dc08 c5c52038 00000020 00000000 c5c53d34 fcda6ff7
[   39.428112] 3ca0: 000014b0 000005a8 c5c53ccc c5c53cb8 c0023d20 c00236fc 00000000 c0378b88
[   39.440199] 3cc0: c5c53cec c5c53cd0 c000eb50 c0023c90 d3b18798 c01510b4 20000013 f200b200
[   39.452304] 3ce0: c5c53cfc c5c53cf0 c0008170 c000eb20 c5c53e04 c5c53d00 c000de34 c000816c
[   39.464415] 3d00: c0d15ae0 015b1e70 000002e8 a525b475 ec27343e d79c38ae 31dfa4d1 fb78745d
[   39.476601] 3d20: fcda6ff7 000014b0 000005a8 c5c53e04 8ecf152d c5c53d4c d3b18798 c01510b4
[   39.488790] 3d40: 20000013 ffffffff c0256a48 c0ff8aa0 c5c52000 40000000 015b1c28 c0d158a0
[   39.500938] 3d60: 000005a8 00000000 c6a5f760 c0257a78 c5c52000 c5c52030 c5c53dc0 00000b50
[   39.513005] 3d80: c5c53dc0 c641f090 c5c53dbc 000005a8 c0022c48 c0048580 00000026 00000000
[   39.525144] 3da0: c5c53e98 00000000 c6810d10 c5c52000 00000000 00000000 00000000 c0ff8b24
[   39.537338] 3dc0: 00000000 000005a8 00000026 000005a8 7fffffff 00000000 00000000 c0ff8aa0
[   39.549555] 3de0: c5c53e98 c5c53e98 c5c53e90 c0ffe040 c5c52000 00000000 c5c53e24 c5c53e08
[   39.561833] 3e00: c0278b40 c02571ec c5c53e90 c5c53e98 00000001 c6b33560 c5c53e84 c5c53e28
[   39.574057] 3e20: c02187a8 c0278b04 00000138 00000000 c5c52000 00002000 c64366a0 00000001
[   39.586231] 3e40: 00000000 c5c53e48 00000000 00000000 c5c53e90 00000001 00000000 00000000
[   39.598360] 3e60: 00000000 c5c53e98 c5c53f78 c6b33560 fffffdee 00002000 c5c53f3c c5c53e88
[   39.610472] 3e80: c0091a6c c02186b0 00000000 00000000 015b10d8 00002000 00000000 00000000
[   39.622579] 3ea0: 00000000 00000001 ffffffff c6b33560 00000000 00000000 00000000 00000000
[   39.634670] 3ec0: c0ffe040 00000000 00000000 00000000 00000000 00000000 c5c53e28 00000000
[   39.646768] 3ee0: 00002000 00000000 00002000 00000000 00000000 00000000 00000000 00000000
[   39.658816] 3f00: 00000000 00000000 00000000 00000000 00000000 00000000 c6b33560 c6b33560
[   39.670830] 3f20: 015b10d8 c5c53f78 015b10d8 00002000 c5c53f6c c5c53f40 c0092280 c00919cc
[   39.682860] 3f40: 00000000 00000000 c036cde8 00000000 00000000 c6b33560 015b10d8 00002000
[   39.694921] 3f60: c5c53fa4 c5c53f70 c0092500 c0092154 c5c53f8c 00000000 00000000 00000000
[   39.707006] 3f80: c5c53fac 000aee40 00000001 015b10d8 00000004 c000e444 00000000 c5c53fa8
[   39.719100] 3fa0: c000e2e0 c00924cc 000aee40 00000001 00000001 015b10d8 00002000 00000000
[   39.731206] 3fc0: 000aee40 00000001 015b10d8 00000004 00002000 7fffffff beea4a38 7fff0000
[   39.743332] 3fe0: 00000000 beea49fc 00010ee0 b6ee5cdc 60000010 00000001 00100005 00000000
[   39.755465] Backtrace: 
[   39.761854] [<c026ac40>] (tcp_v4_early_demux+0x0/0x148) from [<c0249e5c>] (ip_rcv+0x308/0x4c4)
[   39.774466]  r6:0000e8ee r5:c5fb9298 r4:c5838036
[   39.783160] [<c0249b54>] (ip_rcv+0x0/0x4c4) from [<c0229254>] (__netif_receive_skb+0x440/0x61c)
[   39.795934]  r9:c03665d4 r8:c5fb9280 r7:00000000 r6:c69b0000 r5:00000008
r4:c03665b0
[   39.811921] [<c0228e14>] (__netif_receive_skb+0x0/0x61c) from [<c02294a4>] (process_backlog+0x74/0x124)
[   39.825442] [<c0229430>] (process_backlog+0x0/0x124) from [<c022b714>] (net_rx_action+0x9c/0x160)
[   39.838476] [<c022b678>] (net_rx_action+0x0/0x160) from [<c00237a8>] (__do_softirq+0xb8/0x178)
[   39.851233] [<c00236f0>] (__do_softirq+0x0/0x178) from [<c0023d20>] (irq_exit+0x9c/0xa4)
[   39.863464] [<c0023c84>] (irq_exit+0x0/0xa4) from [<c000eb50>] (handle_IRQ+0x3c/0x8c)
[   39.875406]  r4:c0378b88 r3:00000000
[   39.883098] [<c000eb14>] (handle_IRQ+0x0/0x8c) from [<c0008170>] (asm_do_IRQ+0x10/0x14)
[   39.895218]  r6:f200b200 r5:20000013 r4:c01510b4 r3:d3b18798
[   39.905064] [<c0008160>] (asm_do_IRQ+0x0/0x14) from [<c000de34>] (__irq_svc+0x34/0xc8)
[   39.917103] Exception stack(0xc5c53d00 to 0xc5c53d48)
[   39.926258] 3d00: c0d15ae0 015b1e70 000002e8 a525b475 ec27343e d79c38ae 31dfa4d1 fb78745d
[   39.938581] 3d20: fcda6ff7 000014b0 000005a8 c5c53e04 8ecf152d c5c53d4c d3b18798 c01510b4
[   39.950907] 3d40: 20000013 ffffffff
[   39.958530] [<c02571e0>] (tcp_sendmsg+0x0/0xed8) from [<c0278b40>] (inet_sendmsg+0x48/0x80)
[   39.971108] [<c0278af8>] (inet_sendmsg+0x0/0x80) from [<c02187a8>] (sock_aio_write+0x104/0x138)
[   39.983967]  r5:c6b33560 r4:00000001
[   39.991722] [<c02186a4>] (sock_aio_write+0x0/0x138) from [<c0091a6c>] (do_sync_write+0xac/0xf0)
[   40.004612]  r7:00002000 r6:fffffdee r5:c6b33560 r4:c5c53f78
[   40.014531] [<c00919c0>] (do_sync_write+0x0/0xf0) from [<c0092280>] (vfs_write+0x138/0x150)
[   40.027116]  r8:00002000 r7:015b10d8 r6:c5c53f78 r5:015b10d8 r4:c6b33560
[   40.038159] [<c0092148>] (vfs_write+0x0/0x150) from [<c0092500>] (sys_write+0x40/0x80)
[   40.050321]  r8:00002000 r7:015b10d8 r6:c6b33560 r5:00000000 r4:00000000
[   40.061387] [<c00924c0>] (sys_write+0x0/0x80) from [<c000e2e0>] (ret_fast_syscall+0x0/0x30)
[   40.074051]  r8:c000e444 r7:00000004 r6:015b10d8 r5:00000001 r4:000aee40
[   40.085153] Code: 0a00000f e59f30a0 e5845010 e5843064 (e5d5300e) 
[   40.095666] ---[ end trace c2b44c4f94b809d0 ]---
[   40.104712] Kernel panic - not syncing: Fatal exception in interrupt

To reproduce this, I simply run busybox' httpd applet to serve my /boot directory:

busybox httpd -f -h /boot

Then, from another machine on the same LAN segment, I fire a lot of concurrent downloads of my zImage file:

for((i=0; i<100; i++)); do
    curl http://192.168.127.167/zImage >/dev/null 2>&1 & 
done

Then, sooner or later (rather sooner than later, in fact), I get the above kernel panic.

Here is my kernel's .config: http://code.bulix.org/vv3a58-84120?raw

[yann-morin-1998]

BTW, I'm using firmware from cset 320084a.

I'm now building the latest kernel (cset b6a2703) to confirm the issue is still present.
Then, I'll test with latest firmware (cset 89ac8f4).

Edit:
It still fails in the exact same way with these combinations:

• firmware: 320084a kernel: b6a2703
• firmware: 89ac8f4 kernel: b6a2703

[yann-morin-1998]

Here's my cmdline.txt:

dwc_otg.fiq_fix_enable=1 sdhci-bcm2708.sync_after_dma=0 dwc_otg.lpm_enable=0 console=tty1 console=ttyAMA0,115200 root=/dev/mmcblk0p2 rootwait rootfstype=ext4

And here's my config.txt:

arm_freq=700
core_freq=250
disable_overscan=1
sdram_freq=400
over_voltage=0
kernel=zImage
gpu_mem_256=128
gpu_mem_512=256

[yann-morin-1998]

Back with some rather good news: it seems that 245f716 with bcmrpi_defconfig does not exhibit the problem after a lot of testing with the above test-protocol.

I'll test some more with bcmrpi_cutdown_defconfig and bcmrpi_quick_defconfig, too. I'll try to pin-point the exact (subset of) option(s) that is required to trigger/fix this isue (but bisecting a .config will be hard, I already spent some time on this this morning).

As a side note, I would very much like to have a defconfig that enables only the basic RPi-related drivers, with nothing fancy: just support for USB, smsc95xx, i2c, sdhci. In short, only what is strictly required to get all of the RPi hardware up-n-running, and no more. Naively, I expected bcmrpi_defconfig to be just that, but no, it enables a truck-load of unrelated features, and takes ages to build. Is one of bcmrpi_cutdown_defconfig or bcmrpi_quick_defconfig (provided they do not exhibit this issue) supposed to provide that minimal config for the RPi?

Feel free to close this issue if you want.

Thanks! :-)

[popcornmix]

bcmrpi_quick_defconfig is a no modules build, that does include all teh built in hardware, so sounds like what you want.

[yann-morin-1998]

OK, I've found the one option that causes this issue.

If CONFIG_CMA is set (but CONFIG_BCM_VC_CMA is unset), then there is no problem.
If CONFIG_CMA is unset (and thus CONFIG_BCM_VC_CMA is unset too), the issue is present.

I initially disabled CMA as I don't need it, and need as much memory on the ARM side. But I'm happy to let CMA enabled for now, if it is required.

[popcornmix]

Interesting, but I can't see a reason why CMA should be relevant to this panic.
Perhaps @P33M has an idea.

[yann-morin-1998]

OK, indeed, I was mislead by another spurious error. My bad, sorry.

In fact, the kernel panic occurs with CONFIG_PREEMPT. When it is set, the kernel panics. If unset it does not panic (but there are other issues I'll tackle next, which seem related to CMA).

I still have some testing to do, but so far, CONFIG_PREEMPT seems the real culprit for this kernel NULL pointer dereference.

Edit: Confirmed, only removing CONFIG_PREEMPT from my .config makes the issue disapear.

[yann-morin-1998]

After further testing, CONFIG_PREEMPT was the culprit on the .config I pointed to.

But, another .config based on bcmrpi_defconfig, where CONFIG_PREEMPT` is set, does not exhibit the issue.

I'm still trying to narrow down the exact option (or subset of options) that cause the issue... (Damn, I've spent my whole WE on this...).

[P33M]

Can you post both the crashing config and the non-crashing config?

Pastebin or similar would be preferred due to the usual size.

You can force concurrency issues if you enable stuff like lock debugging. Mainly as a result of USB driver interactions and badly timed interrupts.

[yann-morin-1998]

Here's the crashing .config : http://code.bulix.org/vv3a58-84120?raw
Here's the working one : http://code.bulix.org/0ogj08-84147?raw

Note that they are not related. This crashing one was build up from scratch, while the working one is a trimmed-down bcmrpi_defconfig.

I'll look at the enabling/disabling debugging stuff, and see if I can find the one(s) that exhibits the problem. Thanks for the hint! :-)

Edit: paste correct working .config (the previous one was a defconfig).

[yann-morin-1998]

Back with some more news: bcmrpi_quick on rpi-3.6.y and rpi-3.10.y (when it was based on stable/linux-3.10.4) segfaults in the same way.

[P33M]

Can you retry again with both the master and BRANCH=next firmware (provided by rpi-update)?

See http://www.raspberrypi.org/forum/viewtopic.php?f=28&t=70437 for info.

[audetto]

EDIT: forgot to add some context.

I've tried raspbian and archlinux

1. raspbian: using the cm108 soundcard. (before this new firmware there where a lot of "delay: estimated 353, actual 0" under heavy load)
   snd usb error: delay: estimated xxx, actual yyy #541
2. archlinux (3.10): internal audio + bluetooth (kernel panic sooner or later)

Results:

1. less delay: estimated 353, actual 0
2. no panic (not yet at least, 1 hour)

but in both cases there are a lot of NYET + some callbacks missed

overall: massive improvement, at least the system does not crash.
audio still has some glitches, but I would not be able to blame it on a single component

I would like to test the full thing, but bluetooth seems to have some issues in 3.10 which are fixed in 3.13 (I connect a PS3 controller, but /dev/input/js0 is deleted shortly after is created).

How do I try a FIQ-firmware for 3.13?
Do I need to compile https://github.com/raspberrypi/linux/tree/rpi-3.13.y-next on my own?

[ 73.618205] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.620205] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.621070] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.622195] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.624208] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.625072] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.626193] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.628201] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.629079] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 73.630211] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 76.924628] delay: estimated 177, actual 1
[ 77.170960] Transfer to device 4 endpoint 0x2 failed - FIQ timed out. Data may have been lost.
[ 77.177892] delay: estimated 353, actual 0
[ 77.772899] delay: estimated 309, actual 1
[ 78.270780] delay: estimated 353, actual 0
[ 78.670142] dwc_otg_hcd_handle_hc_fsm: 1829 callbacks suppressed
[ 78.670179] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.670398] retire_capture_urb: 1807 callbacks suppressed
[ 78.671218] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.672096] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.673196] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.675200] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.677720] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.679222] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.680095] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.681200] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 78.682075] Transfer to device 4 endpoint 0x2 failed - FIQ reported NYET. Data may have been lost.
[ 140.500254] dwc_otg_hcd_handle_hc_fsm: 148 callbacks suppressed
[ 140.500287] Transfer to device 4 endpoint 0x7 failed - FIQ reported NYET. Data may have been lost.
[ 140.700253] Transfer to device 4 endpoint 0x7 failed - FIQ reported NYET. Data may have been lost.

here is dwc in dmesg

[ 1.403936] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 1.860481] WARN::dwc_otg_hcd_init:1053: FIQ DMA bounce buffers: virt = 0xde414000 dma = 0x5e414000 len=9024
[ 1.890573] dwc_otg: Microframe scheduler enabled
[ 1.911832] dwc_otg bcm2708_usb: DWC OTG Controller
[ 1.918365] dwc_otg bcm2708_usb: new USB bus registered, assigned bus number 1
[ 1.927326] dwc_otg bcm2708_usb: irq 32, io mem 0x00000000
[ 1.962316] usb usb1: Product: DWC OTG Controller
[ 1.968654] usb usb1: Manufacturer: Linux 3.10.30+ dwc_otg_hcd
[ 1.994290] dwc_otg: FIQ enabled
[ 1.994308] dwc_otg: NAK holdoff enabled
[ 1.994320] dwc_otg: FIQ split-transaction FSM enabled
[ 1.994341] Module dwc_common_port init

pi@raspberrypi ~ $ /opt/vc/bin/vcgencmd version
Mar 6 2014 18:58:19
Copyright (c) 2012 Broadcom
version c96cb035fdc907d28db836bbb1606aea2a8e73d9 (clean) (release)