Hi Felipe,
On Mon, Mar 7, 2016 at 11:13 PM, Felipe Balbi <balbi@xxxxxxxxxx> wrote:
>
> Hi,
>
> Victor Dodon <printesoi@xxxxxxxxxxxx> writes:
>> [ text/plain ]
>> Sorry, I accidentally pressed Send
>>
>> On Mon, Mar 7, 2016 at 7:35 PM, Victor Dodon <printesoi@xxxxxxxxxxxx> wrote:
>>> Hi all,
>>>
>>> I have some performance issues with the host port on a Beaglebone
>>> board. I tested with kernel 3.8.13, 3.14.55 and 4.1.18 and the issue
>>> still persists. Running a fio test with 64k random reads from a USB
>>> flash drive yields a maximum of 14402.01 KiB/s (115216.08 Kb/s). The
>>> 3.14 and 4.1 kernels where build with CONFIG_TI_CPPI41_DMA=y. I was
>>> able to get a much better performance on the client USB port by
>>> enabling fifo double buffering. Iperf over a gigabit connection and a Ethernet
>>> to USB adapter plugged in the host port gives a maximum of 180Mbit/s with fifo
>>> double buffering enabled for the ep1 and ep2.
>>>
>>> Are there any known performance issues in the musb driver? For my use
>>> case I need
>>> a higher bandwidth and I would like to improve the host controller,
>>> but I'm a beginner in Kernel hacking and I would appreciate some help,
>>> tips or any cues to start.
>>>
>>> I also found a few problems with the host port. For example:
>>> Using the setup described above (gigabit connection and a Ethernet
>>> to USB adapter plugged in the host port and with a running iSCSI
>>> initiator on the BB,
>>> in usb/musb/musb_core.c if I change mode_4_cfg to enable double
>>> buffering, and I restart the board while doing a dd from the disk
>>> mounted with iSCSI, the kernel stops at:
>>
>> *if I enable double buffering for both RX and TX for only for ep 1
>> then the kernel stops at:
>>
>> [ 233.930764] blk_update_request: I/O error, dev sda, sector 1620736
>> [ 234.451076] musb-hdrc musb-hdrc.1.auto: remove, state 1
>> [ 234.469702] usb usb1: USB disconnect, device number 1
>> [ 234.492716] init: iscsid main process (466) killed by TERM signal
>> [ 234.510663] usb 1-1: USB disconnect, device number 2
>> [ 234.533235] usb 1-1.1: USB disconnect, device number 3
>> [ 234.555153] usb 1-1.3: USB disconnect, device number 4
>> [ 234.586962] musb-hdrc musb-hdrc.1.auto: USB bus 1 deregistered
>> [ 234.606098] reboot: Restarting system
>>
>> if I enable double buffering for RX and TX for ep 1 and 2, only when
>
> you mean you're using FIFO_RXTX ? IIRC, that's only for Isochronous
> endpoints.
No, I use:
static struct musb_fifo_cfg mode_4_cfg[] = {
{ .hw_ep_num = 1, .style = FIFO_TX, .maxpacket = 512, .mode = BUF_DOUBLE, },
{ .hw_ep_num = 1, .style = FIFO_RX, .maxpacket = 512, .mode = BUF_DOUBLE, },
{ .hw_ep_num = 2, .style = FIFO_TX, .maxpacket = 512, },
{ .hw_ep_num = 2, .style = FIFO_RX, .maxpacket = 512, },
...
in the first case, and:
static struct musb_fifo_cfg mode_4_cfg[] = {
{ .hw_ep_num = 1, .style = FIFO_TX, .maxpacket = 512, .mode = BUF_DOUBLE, },
{ .hw_ep_num = 1, .style = FIFO_RX, .maxpacket = 512, .mode = BUF_DOUBLE, },
{ .hw_ep_num = 2, .style = FIFO_TX, .maxpacket = 512, .mode = BUF_DOUBLE, },
{ .hw_ep_num = 2, .style = FIFO_RX, .maxpacket = 512, .mode = BUF_DOUBLE, },
in the second, with a few changes in the last endpoint to fit in 16k.
>
> I'm adding Bin (current MUSB maintainer) to see if he has anything to
> say.
>
> ps: 4.1 is still too old, can you try v4.4 or v4.5-rc6 ?
Ok, I will try the newer kernels.
Thank you very much,
Victor Dodon.
>
>> logging in to the target, the network connectivity fails, I after some
>> time I got:
>>
>> [ 92.176028] udevd[98]: worker [803] /devices/platform/hos
>> t0/session1/target0:0:0/0:0:0:0/block/sda/sda1 timeout; kill it
>> [ 92.190702] udevd[98]: seq 1480
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda1'
>> killed
>> [ 92.202237] udevd[98]: worker [805]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a2
>> timeout; kill it
>> [ 92.216125] udevd[98]: seq 1481
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda2'
>> killed
>> [ 92.226088] udevd[98]: worker [806]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a3
>> timeout; kill it
>> [ 92.240727] udevd[98]: seq 1482
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda3'
>> killed
>> [ 92.252076] udevd[98]: worker [807]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a4
>> timeout; kill it
>> [ 92.265958] udevd[98]: seq 1483
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda4'
>> killed
>> [ 92.276066] udevd[98]: worker [811]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:1/block/sdb ti
>> meout; kill it
>> [ 92.290420] udevd[98]: seq 1477
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:1/block/sdb' kill
>> ed
>> [ 92.299911] udevd[98]: worker [813]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a5
>> timeout; kill it
>> [ 92.314794] udevd[98]: seq 1484
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda5'
>> killed
>> [ 92.326211] udevd[98]: worker [814]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a6
>> timeout; kill it
>> [ 92.340026] udevd[98]: seq 1485
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda6'
>> killed
>> [ 92.350116] udevd[98]: worker [815]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a7
>> timeout; kill it
>> [ 92.364315] udevd[98]: seq 1486
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda7'
>> killed
>> [ 92.374220] udevd[98]: worker [816]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a8
>> timeout; kill it
>> [ 92.388688] udevd[98]: seq 1487
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda8'
>> killed
>> [ 92.399953] udevd[98]: worker [817]
>> /devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sd a9
>> timeout; kill it
>> [ 92.413449] udevd[98]: seq 1488
>> '/devices/platform/host0/session1/target0:0:0/0:0:0:0/block/sda/sda9'
>> killed
>> [ 110.497428] ------------[ cut here ]------------
>> [ 110.501976] WARNING: CPU: 0 PID: 842 at
>> ../../../../../tmp/portage/sys-kernel/kernel-beaglebone-4_1-4
>> .1.18/work/kernel-beaglebone-4_1-4.1.18/drivers/dma/cppi41.c:611
>> cppi41_stop_chan+0x26c/0x2d0()
>> [ 110.518903] Modules linked in: r8152 iscsi_tcp libiscsi_tcp
>> libiscsi scsi_transport_iscsi uinput omap _hwspinlock hwspinlock_core
>> cfg80211 fuse nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter
>> ip6_tables sn d_seq_midi snd_seq_midi_event snd_seq snd_rawmidi
>> snd_seq_device ppp_async ppp_generic slhc tun
>> [ 110.544809] CPU: 0 PID: 842 Comm: kworker/0:3 Not tainted 4.1.18+ #42
>> [ 110.551051] Hardware name: Generic AM33XX (Flattened Device Tree)
>> [ 110.556983] Workqueue: events rtl_work_func_t [r8152]
>> [ 110.561924] [<c0016ff0>] (unwind_backtrace) from [<c0012fd0>]
>> (show_stack+0x20/0x24)
>> [ 110.569446] [<c0012fd0>] (show_stack) from [<c065a624>]
>> (dump_stack+0x78/0x94)
>> [ 110.576469] [<c065a624>] (dump_stack) from [<c003d418>]
>> (warn_slowpath_common+0x9c/0xc8)
>> [ 110.584324] [<c003d418>] (warn_slowpath_common) from [<c003d500>]
>> (warn_slowpath_null+0x2c/0x34)
>> [ 110.592850] [<c003d500>] (warn_slowpath_null) from [<c03063a8>]
>> (cppi41_stop_chan+0x26c/0x2d0)
>> [ 110.601222] [<c03063a8>] (cppi41_stop_chan) from [<c044e708>]
>> (cppi41_dma_channel_abort+0x174/0x1ec)
>> [ 110.610088] [<c044e708>] (cppi41_dma_channel_abort) from
>> [<c044842c>] (musb_cleanup_urb+0x70/0x144)
>> [ 110.618866] [<c044842c>] (musb_cleanup_urb) from [<c0448604>]
>> (musb_urb_dequeue+0x104/0x124)
>> [ 110.627067] [<c0448604>] (musb_urb_dequeue) from [<c041d260>]
>> (usb_hcd_unlink_urb+0x94/0xb4)
>> [ 110.635260] [<c041d260>] (usb_hcd_unlink_urb) from [<c041e244>]
>> (usb_kill_urb+0x68/0xe4)
>> [ 110.643117] [<c041e244>] (usb_kill_urb) from [<bf138210>]
>> (r8152_get_eee+0x394/0x3e8 [r8152])
>> [ 110.651419] [<bf138210>] (r8152_get_eee [r8152]) from [<bf13bbe8>]
>> (rtl8153_enable+0x198/0x1a8 [r8152])
>> [ 110.660543] [<bf13bbe8>] (rtl8153_enable [r8152]) from [<bf13bc1c>]
>> (rtl8153_disable+0x24/0x30 [r8152])
>> [ 110.669666] [<bf13bc1c>] (rtl8153_disable [r8152]) from
>> [<bf13b5f0>] (rtl_work_func_t+0x11c/0x3c0 [r8152])
>> [ 110.679044] [<bf13b5f0>] (rtl_work_func_t [r8152]) from
>> [<c0052368>] (process_one_work+0x21c/0x398)
>> [ 110.687825] [<c0052368>] (process_one_work) from [<c0053554>]
>> (worker_thread+0x358/0x49c)
>> [ 110.695769] [<c0053554>] (worker_thread) from [<c0057a84>]
>> (kthread+0xe0/0xf0)
>> [ 110.702791] [<c0057a84>] (kthread) from [<c000f328>]
>> (ret_from_fork+0x14/0x2c)
>> [ 110.709793] ---[ end trace a493bc1b05f79d91 ]---
>> [ 110.714328] musb_host_rx 1654: RX2 dma busy, csr 2001
>> [ 180.325745] INFO: task udevd:803 blocked for more than 60 seconds.
>> [ 180.331877] Tainted: G W 4.1.18+ #42
>> [ 180.337010] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
>> disables this message.
>> [ 180.344639] udevd D c065bc94 0 803 98 0x00000005
>> [ 180.350971] [<c065bc94>] (__schedule) from [<c065be4c>] (schedule+0xc0/0xe4)
>> [ 180.357860] [<c065be4c>] (schedule) from [<c065f7a8>]
>> (schedule_timeout+0x2c/0x1e4)
>> [ 180.365335] [<c065f7a8>] (schedule_timeout) from [<c065b808>]
>> (io_schedule_timeout+0xb8/0x134)
>> [ 180.373729] [<c065b808>] (io_schedule_timeout) from [<c065c6bc>]
>> (bit_wait_io+0x64/0x6c)
>> [ 180.381619] [<c065c6bc>] (bit_wait_io) from [<c065c518>]
>> (__wait_on_bit_lock+0x6c/0xb4)
>> [ 180.389425] [<c065c518>] (__wait_on_bit_lock) from [<c00f0dcc>]
>> (__lock_page+0x70/0x80)
>> [ 180.397245] [<c00f0dcc>] (__lock_page) from [<c00fe83c>]
>> (truncate_inode_pages_range+0x3e0/0x458)
>> [ 180.405899] [<c00fe83c>] (truncate_inode_pages_range) from
>> [<c00fe8dc>] (truncate_inode_pages+0x28/0x30)
>> [ 180.415136] [<c00fe8dc>] (truncate_inode_pages) from [<c0165544>]
>> (kill_bdev+0x48/0x4c)
>> [ 180.422943] [<c0165544>] (kill_bdev) from [<c0166b68>]
>> (__blkdev_put+0x98/0x1b4)
>> [ 180.430158] [<c0166b68>] (__blkdev_put) from [<c01674d8>]
>> (blkdev_put+0x124/0x134)
>> [ 180.437540] [<c01674d8>] (blkdev_put) from [<c0167588>]
>> (blkdev_close+0x28/0x30)
>> [ 180.444779] [<c0167588>] (blkdev_close) from [<c01346ec>] (__fput+0xf8/0x1d4)
>> [ 180.451753] [<c01346ec>] (__fput) from [<c0134838>] (____fput+0x18/0x1c)
>> [ 180.458309] [<c0134838>] (____fput) from [<c00562e0>]
>> (task_work_run+0xc4/0xd8)
>> [ 180.465460] [<c00562e0>] (task_work_run) from [<c00401c4>]
>> (do_exit+0x440/0x8f0)
>> [ 180.472684] [<c00401c4>] (do_exit) from [<c004071c>]
>> (do_group_exit+0x5c/0xcc)
>> [ 180.479743] [<c004071c>] (do_group_exit) from [<c004a9b8>]
>> (get_signal+0x4e8/0x544)
>> [ 180.487229] [<c004a9b8>] (get_signal) from [<c00123f8>]
>> (do_signal+0x9c/0x360)
>> [ 180.494285] [<c00123f8>] (do_signal) from [<c0012848>]
>> (do_work_pending+0x60/0xb8)
>> [ 180.501671] [<c0012848>] (do_work_pending) from [<c000f2cc>]
>> (work_pending+0xc/0x20)
>> [ 180.509218] Kernel panic - not syncing: hung_task: blocked tasks
>> [ 180.515051] CPU: 0 PID: 18 Comm: khungtaskd Tainted: G W
>> 4.1.18+ #42
>> [ 180.522302] Hardware name: Generic AM33XX (Flattened Device Tree)
>> [ 180.528229] [<c0016ff0>] (unwind_backtrace) from [<c0012fd0>]
>> (show_stack+0x20/0x24)
>> [ 180.535747] [<c0012fd0>] (show_stack) from [<c065a624>]
>> (dump_stack+0x78/0x94)
>> [ 180.542757] [<c065a624>] (dump_stack) from [<c06582e0>] (panic+0x98/0x208)
>> [ 180.549434] [<c06582e0>] (panic) from [<c00b7904>] (watchdog+0x330/0x360)
>> [ 180.556030] [<c00b7904>] (watchdog) from [<c0057a84>] (kthread+0xe0/0xf0)
>> [ 180.562623] [<c0057a84>] (kthread) from [<c000f328>]
>> (ret_from_fork+0x14/0x2c)
>>
>> Both problems happen with kernel 4.1.18 from
>> https://github.com/beagleboard/linux/commits/4.1
>>
>> Thank you,
>> Victor Dodon.
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-usb" in
>> the body of a message to majordomo@xxxxxxxxxxxxxxx
>> More majordomo info at http://vger.kernel.org/majordomo-info.html
>
> --
> balbi
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
