Re: [PATCH] usb: musb: musb_host: Introduce postponed URB giveback

[Matwey V. Kornilov]

 which i

2017-04-28 14:58 GMT+03:00 Bin Liu <b-liu@xxxxxx>:
> On Fri, Apr 28, 2017 at 10:04:30AM +0300, Matwey V. Kornilov wrote:
>> 2017-04-27 20:13 GMT+03:00 Bin Liu <b-liu@xxxxxx>:
>> > On Thu, Apr 27, 2017 at 07:26:31PM +0300, Matwey V. Kornilov wrote:
>> >> 2017-04-27 18:35 GMT+03:00 Bin Liu <b-liu@xxxxxx>:
>> >> > Hi Matwey,
>> >> >
>> >> > On Thu, Apr 27, 2017 at 01:20:33PM +0300, Matwey V. Kornilov wrote:
>> >> >> This commit changes the order of actions undertaken in
>> >> >> musb_advance_schedule() in order to overcome issue with broken
>> >> >> isochronous transfer [1].
>> >> >>
>> >> >> There is no harm to split musb_giveback into two pieces.  The first
>> >> >> unlinks finished urb, the second givebacks it. The issue here that
>> >> >> givebacking may be quite time-consuming due to urb->complete() call.
>> >> >> As it happens in case of pwc-driven web cameras. It may take about 0.5
>> >> >> ms to call __musb_giveback() that calls urb->callback() internally.
>> >> >> Under specific circumstances setting MUSB_RXCSR_H_REQPKT in subsequent
>> >> >> musb_start_urb() for the next urb will be too late to produce physical
>> >> >> IN packet. Since auto req is not used by this module the exchange
>> >> >> would be as the following:
>> >> >>
>> >> >> [        ]   7.220456 d=  0.000997 [182   +  3.667] [  3] IN   : 4.5
>> >> >> [    T   ]   7.220459 d=  0.000003 [182   +  7.000] [800] DATA0: [skipped]
>> >> >> [        ]   7.222456 d=  0.001997 [184   +  3.667] [  3] IN   : 4.5
>> >> >> [        ]   7.222459 d=  0.000003 [184   +  7.000] [  3] DATA0: 00 00
>> >> >>
>> >> >> It is known that missed IN in isochronous mode makes some
>> >> >> perepherial broken. For instance, pwc-driven or uvc-driven
>> >> >> web cameras.
>> >> >> In order to workaround this issue we postpone calling
>> >> >> urb->callback() after setting MUSB_RXCSR_H_REQPKT for the
>> >> >> next urb if there is the next urb pending in queue.
>> >> >>
>> >> >> [1] https://www.spinics.net/lists/linux-usb/msg145747.html
>> >> >>
>> >> >> Fixes: f551e1352983 ("Revert "usb: musb: musb_host: Enable HCD_BH flag to handle urb return in bottom half"")
>> >> >> Signed-off-by: Matwey V. Kornilov <matwey@xxxxxxxxxx>
>> >> >
>> >> > Thanks for the effort of working on this long standing issue, I know you
>> >> > have spent alot of time on it, but what I am thinking is instead of
>> >> > workaround the problem we need to understand the root cause - why
>> >> > uvc-video takes longer to exec the urb callback, why only am335x
>> >> > reported this issue. This is on my backlog, just seems never got time
>> >> > for it...
>> >>
>> >> Have you tried other SoCs with Invetra MUSB?
>> >
>> > That is the plan, I got an A20 board, but haven't bring it up yet.
>> >
>> >>
>> >> >
>> >> > Ideally MUSB driver should be just using HCD_BH flag and let the core to
>> >> > handle the urb callback, regardless the usb transfer types.
>> >>
>> >> I think the only reason why everything worked before with HCD_BH is
>> >> that execution of urb->callback() was placed after musb_start(). The
>> >> order of operations matters.
>> >> However, you said that something was also wrong with HCD_BH and other
>> >> peripherals.
>> >
>> > HCD_BH flag cause some issues which are docummented in the commit log of
>> > f551e1352983.
>> > But even with HCD_BH flag, it didn't work for uvc webcams, it still misses
>> > IN tokens. It might helps pwc webcams though.
>>
>> pwc webcams work with HCD_BH fine indeed.
>
> yeah, this is what you told long time ago.
>
>>
>> >
>> >> > The MUSB drivers are already messy and complicated enough for
>> >> > maintenance, I'd like to understand the root cause of the delay first
>> >> > before decide how to solve the issue.
>> >> >
>> >>
>> >> I feel from playing with OpenVizsla that REQPKT should be set well in
>> >> advance. So, time window to set the flag is actually smaller than 1
>> >> ms.
>> >> urb->callback() is never takes longer than 0.4 ms for pwc driver, but
>> >> INs are skipped.
>> >
>> > Setting REQPKT in advance might be the solution, but I'd like to
>> > understand why only Isoch transfer shows such issue, and why only am335x
>> > reports this issue. The later concerns me more if this would be a
>> > system issue not only in usb module.
>>
>> 0.4 ms is about 100000 CPU cycles given that CPU is running at 275Mhz
>> (which is the lowest cpufreq). Long time ago, I run pwc webcam with
>> SIS Vortex86 at 200Mhz It worked fine. I would not say that it is
>> extraordinary value.
>> Do you think that somewhere CPU cycles are wasted globally for some reason?
>
> Depends on how to interpret 'wasted', my understanding the issue is the
> core urb giveback holds a spinlock and in uvc case the giveback takes
> longer to finish (I guess the same in pwc case), so the musb driver
> doesn't get a chance to re-program the controller on time, which causes
> missing issuingIN tokens.
>
> The questions are, why uvc takes longer to run urb giveback (which holds
> a spinlock), and is it am335x specific issue...

It is not clear how does it hold a spinlock on a BeagleBone which is
single-core system.
I mean if it is waiting for blocked lock it will be waiting forever,
because it is in interrupt context on single core system.
Here it is waiting for finite time amount. It is also quite unlikely
that spinlocks are implemented inefficiently for arm architecture.
So, I tested with CONFIG_SMP=y which is default in my distro kernel.
Do you think it is worth to try CONFIG_SMP=n or have you already tried
UP kernel configuration?

>
> Regards,
> -Bin.
>



-- 
With best regards,
Matwey V. Kornilov.
Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia
119234, Moscow, Universitetsky pr-k 13, +7 (495) 9392382