I am writing an application to send data over USB in a streaming fashion. I have semi hard realtime constraints on the data I am streaming (think of it as audio). To cover my needs, I schedule 16 BULK write transfers (using libusb for now), and one READ transfer (I receive way less data that I write).
This is a stock TI SDK 7.0 3.12.10 kernel (with the PVR and wifi firmwares, I am happy to provide an untainted kernel trace if you deem it necessary), running on an AM335x.
I sometimes run into the following kernel WARN, which I can kind of trace down to usbfs trying to schedule a new URB. After the WARN, the kernel hangs for a decent amount of time (which I think is because of the busy look in musb_h_tx_flush_fifo) all my BULK transfers timeout, and USB usually doesn't work at all anymore, all I can do is reboot.
The interesting part is that the probability for the WARN goes up when I set the priority of my program to a higher prio (-19 or SCHED_FIFO / SCHED_RR). I thought at first that my program was outrunning / hammering the usb host driver, so I tried out using RT_PREEMPT and setting the prio of the musb_irq thread high. This causes it to fail almost immediately, which suggests to me that the hardware is actually not keeping up with the kernel. Is there a way for me to schedule a running buffer of USB transfers, but throttle it so hardware doesn't get lost? This also happens when reducing the number of concurrent URBs to 4 or less. At 1 or 2 URBs, I don't have enough buffer space to keep up a smooth running "realtime" transfer.
I found a couple of indications of other drivers (cdc_acm gadget, serial host) triggering this bug, but that's about it.
I would be very glad for any suggestions, I am at my wits end on this one (save digging into the musb code, which is too much for me to handle with my limited/outdated kernel experience).
Regards, Manuel
[ 611.641993] WARNING: CPU: 0 PID: 583 at drivers/usb/musb/musb_host.c:129 musb_h_tx_flush_fifo+0xac/0xe8 [musb_hdrc]()
[ 611.653254] Could not flush host TX10 fifo: csr: 0003
[ 611.658614] Modules linked in: g_gilchrist(O) omaplfb(O) bufferclass_ti(O) pvrsrvkm(O) wl18xx wlcore mac80211 libcomposite configfs musb_dsps cfg80211 musb_hdrc musb_am335x tmp006 tsl2x7x_core(C) wlcore_sdio pixcir_i2c_ts industrialio lm75
[ 611.681291] CPU: 0 PID: 583 Comm: usbThread Tainted: G WC O 3.12.10 #1
[ 611.688864] Backtrace:
[ 611.691498] [<c0012704>] (dump_backtrace+0x0/0x10c) from [<c00129e8>] (show_stack+0x18/0x1c)
[ 611.700455] r6:bf038bd0 r5:00000009 r4:cc4d7c58 r3:00000000
[ 611.706520] [<c00129d0>] (show_stack+0x0/0x1c) from [<c04fcb40>] (dump_stack+0x20/0x28)
[ 611.715038] [<c04fcb20>] (dump_stack+0x0/0x28) from [<c0043f04>] (warn_slowpath_common+0x70/0x90)
[ 611.724475] [<c0043e94>] (warn_slowpath_common+0x0/0x90) from [<c0043f5c>] (warn_slowpath_fmt+0x38/0x40)
[ 611.734537] r8:bf042078 r7:00000003 r6:00000000 r5:00000003 r4:d08ee5a2
[ 611.741744] [<c0043f24>] (warn_slowpath_fmt+0x0/0x40) from [<bf038bd0>] (musb_h_tx_flush_fifo+0xac/0xe8 [musb_hdrc])
[ 611.752912] r3:0000000a r2:bf040720
[ 611.756800] [<bf038b24>] (musb_h_tx_flush_fifo+0x0/0xe8 [musb_hdrc]) from [<bf0396fc>] (musb_start_urb+0x59c/0x988 [musb_hdrc])
[ 611.769060] [<bf039160>] (musb_start_urb+0x0/0x988 [musb_hdrc]) from [<bf039bf4>] (musb_advance_schedule+0x10c/0x294 [musb_hdrc])
[ 611.781504] [<bf039ae8>] (musb_advance_schedule+0x0/0x294 [musb_hdrc]) from [<bf03a500>] (musb_cleanup_urb.isra.19+0x80/0xc4 [musb_hdrc])
[ 611.794688] [<bf03a480>] (musb_cleanup_urb.isra.19+0x0/0xc4 [musb_hdrc]) from [<bf03a7ec>] (musb_urb_dequeue+0x150/0x1b0 [musb_hdrc])
[ 611.807422] r7:60010013 r6:cd50bec0 r5:00000000 r4:cc4912c0
[ 611.813517] [<bf03a69c>] (musb_urb_dequeue+0x0/0x1b0 [musb_hdrc]) from [<c037e6ac>] (unlink1+0x34/0x104)
[ 611.823601] [<c037e678>] (unlink1+0x0/0x104) from [<c037f61c>] (usb_hcd_unlink_urb+0x88/0xd0)
[ 611.832649] r8:0000550b r7:fffffffe r6:60010013 r5:cc4912c0 r4:00000000
r3:cd7b2000
[ 611.841033] [<c037f594>] (usb_hcd_unlink_urb+0x0/0xd0) from [<c0380a00>] (usb_kill_urb+0x5c/0xec)
[ 611.850451] r7:cd7b2000 r6:60010013 r5:cc4912cc r4:cc4912c0
[ 611.856514] [<c03809a4>] (usb_kill_urb+0x0/0xec) from [<c038a588>] (usbdev_ioctl+0x434/0x1edc)
[ 611.865656] r5:cc4912c0 r4:cd7b209c
[ 611.869490] [<c038a154>] (usbdev_ioctl+0x0/0x1edc) from [<c00e137c>] (do_vfs_ioctl+0x3d0/0x57c)
[ 611.878747] [<c00e0fac>] (do_vfs_ioctl+0x0/0x57c) from [<c00e15a0>] (SyS_ioctl+0x78/0x88)
[ 611.887450] [<c00e1528>] (SyS_ioctl+0x0/0x88) from [<c000f4e0>] (ret_fast_syscall+0x0/0x30)
[ 611.896313] r9:cc4d6000 r8:c000f664 r7:00000036 r6:000a1108 r5:00000000
r4:0008a248
[ 611.904678] ---[ end trace dc68f199627a2b5b ]---