Freezing issue with Preempt-RT on OpenWRT MIPS

[Rob Connolly]

Hi All,

I have already asked this question on the linux-rt-users mailing list 
and received no response, so I thought I' try here instead.

I am attempting to use the rt patch set on an OpenWRT MIPS based system 
(ar71xx). I'm having some issues loading/using certain kernel modules, 
specifically for ethernet and USB support. The symptoms I am 
experiencing are:

1. The system will freeze completely after loading the usb modules 
(manually with insmod). Specifically this is after loading 
ehci_platform. The system appears to detect the hardware and then lock 
up, it is then rebooted by the watchdog a few seconds later. See below:

root at OpenWrt:/# insmod /lib/modules/3.10.32/nls_base.ko
root at OpenWrt:/# insmod /lib/modules/3.10.32/nls_base.procd: -
root at OpenWrt:/# insmod /lib/modules/3.10.32/usb-common.ko
root at OpenWrt:/# insmod /lib/modules/3.10.32/usbcore.ko
[   51.150000] usbcore: registered new interface driver usbfs
[   51.160000] usbcore: registered new interface driver hub
[   51.160000] usbcore: registered new device driver usb
root at OpenWrt:/# insmod /lib/modules/3.10.32/ehci-hcd.ko
[   58.850000] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
root at OpenWrt:/# insmod /lib/modules/3.10.32/ohci-hcd.ko
[   65.730000] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
root at OpenWrt:/# insmod /lib/modules/3.10.32/ehci-platform.ko
[   77.830000] ehci-platform: EHCI generic platform driver
[   77.830000] ehci-platform ehci-platform: EHCI Host Controller
[   77.840000] ehci-platform ehci-platform: new USB bus registered, 
assigned bus number 1
[   77.850000] ehci-platform ehci-platform: irq 3, io mem 0x1b000000
[   77.880000] ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
[   77.880000] hub 1-0:1.0: USB hub found
[   77.910000] hub 1-0:1.0: 1 port detected
<lock up and reboot>

2. The second issue is similar but occurs when using the ethernet. I 
have the atheros ethernet drivers built into the kernel and can boot to 
a console with the interface disabled. I can even bring the interface up 
with ifconfig. However, the system freezes (as above) upon sending or 
receiving the first network packet.

Investigating further and having read up on some of the debug options. I 
have turned on LOCKUP_DETECTOR and BOOTPARAM_SOFTLOCKUP_PANIC. 
Unfortunately I can't turn on the hard lockup detector since the 
hardware doesn't have a nmi watchdog. I also compiled in debugging 
symbols and enabled DEBUG_BUGVERBOSE in order to get a call trace.

Here is the output of the kernel panic for the USB case above:

[  104.060000] BUG: soft lockup - CPU#0 stuck for 22s! [insmod:1053]
[  104.060000] Modules linked in: ehci_platform(+) ohci_hcd ehci_hcd 
usbcore usb_common nls_base pps_gpio_poll pps_core ath9k ath9k_common 
ath9k_hw ath mac80211 cfg80211 compat
[  104.060000] CPU: 0 PID: 1053 Comm: insmod Not tainted 3.10.32-rt31 #1
[  104.060000] task: 87a1d420 ti: 87044000 task.ti: 87044000
[  104.060000] $ 0   : 00000000 0000006e 10000000 00000000
[  104.060000] $ 4   : 00000000 013fffff 00000002 87a1d420
[  104.060000] $ 8   : 00000001 00000004 00000010 3120706f
[  104.060000] $12   : 00000000 87b88124 00000000 3d2b7573
[  104.060000] $16   : f0000000 10000000 8725b800 0000000a
[  104.060000] $20   : 87813a00 00000001 00000002 00000064
[  104.060000] $24   : 00000010 8007142c
[  104.060000] $28   : 87044000 87045850 00000001 80060890
[  104.060000] Hi    : 00000011
[  104.060000] Lo    : 00000001
[  104.060000] epc   : 80068144 preempt_schedule_irq+0x40/0x80
[  104.060000]     Not tainted
[  104.060000] ra    : 80060890 need_resched+0x28/0x30
[  104.060000] Status: 1100dc03    KERNEL EXL IE
[  104.060000] Cause : 40808800
[  104.060000] PrId  : 0001974c (MIPS 74Kc)
[  104.060000] Kernel panic - not syncing: softlockup: hung tasks
[  104.060000] CPU: 0 PID: 1053 Comm: insmod Not tainted 3.10.32-rt31 #1
[  104.060000] Stack : 00000000 00000000 00000000 00000000 80392e72 
00000039 87a1d5e4 00000068
[  104.060000]       802df1c0 80333d1b 0000041d 80392624 87a1d5e4 
00000068 ffffffff 042c227f
[  104.060000]       00000068 8007a288 00000000 80077834 00000000 
00000040 802e0be8 870455b4
[  104.060000]       00000000 00000000 00000000 00000000 00000000 
00000000 00000000 00000000
[  104.060000]       00000000 00000000 00000000 00000000 00000000 
00000000 00000000 87045540
[  104.060000]       ...
[  104.060000] Call Trace:
[  104.060000] [<8006e94c>] show_stack+0x48/0x70
[  104.060000] [<8007764c>] panic+0xcc/0x20c
[  104.060000] [<800b6110>] watchdog_timer_fn+0x16c/0x19c
[  104.060000] [<8009995c>] __run_hrtimer.isra.26+0x80/0x104
[  104.060000] [<8009a33c>] hrtimer_interrupt+0x204/0x494
[  104.060000] [<80070770>] c0_compare_interrupt+0x4c/0x5c
[  104.060000] [<800b69a8>] handle_irq_event_percpu+0x74/0x1e8
[  104.060000] [<800b96e4>] handle_percpu_irq+0x54/0x84
[  104.060000] [<800b62c0>] generic_handle_irq+0x28/0x44
[  104.060000] [<8006be28>] do_IRQ+0x1c/0x2c
[  104.060000] [<80060820>] ret_from_irq+0x0/0x4
[  104.060000] [<80068144>] preempt_schedule_irq+0x40/0x80
[  104.060000] [<80060890>] need_resched+0x28/0x30
[  104.060000]

 From what I can tell it looks like it gets stuck in 
preempt_schedule_irq, but I'm not sure why need_resched should be below 
that in the call stack.

Does anyone have any idea what might be going on here or any experience 
with similar issues which may help?

Any help appreciated.

Regards,

Rob Connolly
###########################################################################################
This communication, including any attachments, is confidential. If you are not the intended
recipient, you should not read it - please contact me immediately, destroy it, and do not
copy or use any part of this communication or disclose anything about it.
###########################################################################################