2013/11/19 Alan Stern <stern@xxxxxxxxxxxxxxxxxxx>:
> Please use Reply-To-All so that your message gets sent to the mailing
> list as well as to me.
>
> On Sat, 16 Nov 2013, yoma sophian wrote:
>
>> hi alan:
>>
>> > There are other examples in the log like this one. To fix the problem
>> > you could put more packets in each URB, or use more URBs, or eliminate
>> > the large interrupt latency.
>> Thanks for your comment, it is really thoughtful explanation.
>>
>> >
>> >> My questions are:
>> >> 1. in usb driver,
>> >> ehci-sched.c --> itd_complete ->
>> >>
>> >> if (unlikely (t & ISO_ERRS)) {
>> >> ......................
>> >> } else if (likely ((t & EHCI_ISOC_ACTIVE) == 0)) {
>> >> ........................
>> >> } else {
>> >> /* URB was too late */
>> >> urb->error_count++;
>> >> }
>> >> EXDEV seems come from above comment " /*URB was too late */"
>> >
>> > Actually, I expect it comes from the "t & ISO_ERRS" test.
>>
>> if it comes from "t & ISO_ERRS", after reading the case "t &
>> ISO_ERRS", I found desc->status will be update to
>> one fo -ENOSR , ECOMM, -EOVERFLW and -EPROTO.
>
> You're right; it can't be that case after all. It must be the "URB was
> too late case".
>
> However, that case should never occur when an URB is submitted with
> URB_ISO_ASAP -- unless something is wrong with the EHCI hardware.
>
>> >> if my conclusion is correct, why we said "urb was too late"?
>> >> Does it mean urb too late to send or too late to service?
>> >
>> > The comment means "too late to service".
>>
>> Does that mean
>> 1. iso complete irq happen but
>> 2. scan_isoc is too late to be called, such as delaying 30 ms, etc.
>>
>> if so, the EHCI_ISOC_ACTIVE will be 0 and should not run into this case.
>
> No, it means the URB was submitted too late for the hardware to carry
> out the transfers at their scheduled times.
>
>> >> 2. In my case, the urbs are always submitted with URB_ISO_ASAP.
>> >
>> > URBs with ISO_ASAP are never too late to service. That's part of the
>> > reason I suspect the device stopped sending data.
>
> But that was wrong. So it looks like the EHCI hardware is
> malfunctioning.
>
>> >> Except itd_complete is there any place will let iso EXDEV happen?
>> >
>> > Yes, depending on which version of the kernel you are using,
>> > iso_stream_schedule can also have that effect.
>> My kernel version is 3.8.13
>>
>> >
>> > However, the problem doesn't lie in the ehci-hcd driver. The problem
>> > lies in the fact that you aren't submitting URBs fast enough to keep
>> > the isochronous pipeline filled.
>> I got it. :)
>>
>>
>> BTW, I have one question.
>> 1. for iso in case:
>> even iso in is too late to send, ehci driver still put those delay itd
>> to the period scheduling list.
>
> This never happens with URB_ISO_ASAP. Instead, if an URB is too late
> to be sent, the driver reschedules it for a later time.
>
>> That mean in token will firing on the bus.
>
> No. During the interval between when the URB _should_ have been
> scheduled and when it actually _was_ scheduled, no IN tokens will be
> sent.
>
> However, in your case it looks like the EHCI controller went crazy and
> didn't send any IN tokens even when it should have.
>
> Here's the first place in your log where a problem occurs:
>
> d8a80400 78915228 C Zi:1:003:2 0:8:111:0 10 0:0:100 0:512:100
> d8a80400 78923303 S Zi:1:003:2 -115:8:0 10 -18:0:512 -18:512:512
> d8a80800 78925390 C Zi:1:003:2 0:8:191:0 10 0:0:100 0:512:100
> d8a80800 78927016 S Zi:1:003:2 -115:8:0 10 -18:0:512 -18:512:512
> d8a80400 78941545 C Zi:1:003:2 0:8:319:10 10 -18:0:0 -18:512:0
>
> In the first two lines, URB d8a80400 completes at 78.915 but doesn't
> get resubmitted until 78.923, which is 8 ms later. In the meantime,
> URB d8a80800 was running, and it completes at 78.925.
>
> Because there is only 2 ms remaining in the pipeline when d8a80400 is
> resubmitted, the URB_ISO_ASAP flag causes it to be delayed. Normally
> it would have been scheduled to start in uframe 271, but instead it was
> scheduled to start in uframe 319, which was 6 ms later (I don't
> understand why this delay was so large; it shouldn't be more than 2
> ms). This means that 6 schedule slots were left empty -- no IN tokens.
>
> On the last line, you can see where d8a80400 completed after the delay.
> This line is full of -18 errors, which means the hardware did not carry
> out the transfers even though they were added to the schedule well in
> advance. In fact, the hardware did not carry out any more transfers
> until almost 3 seconds later!
>
>> if device response data, ehci driver will go into below a) or b)
>
> No. If the host sends an IN token then the driver will go into case a
> or case b. If the host receives valid data from the device, the driver
> will go into case b.
>
>> if device not response, scan_iso will be called by periodically
>> ehci_work timer and clean it.
>
> If the device does not send data, the driver will go into case a. The
> only reason for the periodic timer to fire is if the hardware isn't
> generating interrupts properly. If that happens, the driver will go
> into case c.
>
>> ehci driver will go in c) and -EXDEV will keep not modify.
>>
>> 1. for iso out case:
>> even iso out is too late to send, ehci driver still put those delay
>> itd to the period scheduling list.
>> That mean out token and out data will firing on the bus.
>
> No, OUT works the same way as IN, except that the device never sends
> anything.
>
>> if device response data, ehci driver will go into below a) or b)
>
> The device never sends anything. If the hardware is working correctly,
> the driver will always go into case b.
>
>> since there is no ACK in iso, ehci driver will never go in c)
>
> The driver will go into case c if the hardware isn't working right.
>
>> if (unlikely (t & ISO_ERRS)) {
>> ...................... (case a)
>> } else if (likely ((t & EHCI_ISOC_ACTIVE) == 0)) {
>> ........................(case b)
>> } else {
>> ........................(case c)
>> /* URB was too late */
>> urb->error_count++;
>> }
>>
>> Appreciate your kind help,
>
> Have you tried running the same test using a regular PC, rather than an
> embedded system?
>
> Alan Stern
>
Attachment:
Serial-COM5-115200-11_23_14_44.log
Description: Binary data
Attachment:
webcam.video.lag.png
Description: PNG image
