Re: some question about EXDEV status in period schedule

2013-12-03 Thread Alan Stern
On Tue, 3 Dec 2013, yoma sophian wrote:

> > This isn't a race condition, because the driver does not terminate
> > isochronous URBs before they are scheduled to end.
> >
> > For example, suppose there was an isochronous URB that was scheduled to
> > transmit packets during microframes 100, 180, 260, and 340.  If an
> > interrupt for a bulk URB happens during microframe 212, the driver will
> > not terminate the isochronous URB, because it is not scheduled to end
> > yet.  But if an interrupt for a bulk URB happens during microframe 347,
> > then the driver will terminate the isochronous URB, because that is
> > after the scheduled end (which is microframe 340).
> how about situation like below:
> HW Frame index is located at microframe 90. And there was an
> isochronous URB that was scheduled to transmit packets during
> microframes 100, 180, 260, and 340.
> 
> Interrupt happen for Bulk when HW increase Frame index to 98.
> 
> After driver scan asynchronous schedule,  driver finds
> ehci->isoc_count != 0 and start scan_isoc.
> Isn't it possible that Driver may drop those previous scheduled
> isochronous packets?

No, it's not possible.  The packets won't be removed from the schedule 
until after microframe 340.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: some question about EXDEV status in period schedule

2013-12-02 Thread yoma sophian
2013/12/2 Alan Stern :
> On Sun, 1 Dec 2013, yoma sophian wrote:
>
>> >> Suppose itds are submitted then ehci_work is triggered by bulk
>> >> interrupt and ehci->isoc_count >0.
>> >>
>> >> The race condition may happen if hardware hasn't handled those itds, 
>> >> right?
>> >
>> > I don't know what race condition you are talking about.  Please explain
>> > in more detail.
>>
>> 1. submit iso urbs ehci->periodic_count ++
>> 2. interrupt for bulk happen
>> 3. scan async
>> 4. scan iso schedule, since ehci->periodic_count != 0
>> 5. clear urb if host hasn't enough time to handle it
>
> This isn't a race condition, because the driver does not terminate
> isochronous URBs before they are scheduled to end.
>
> For example, suppose there was an isochronous URB that was scheduled to
> transmit packets during microframes 100, 180, 260, and 340.  If an
> interrupt for a bulk URB happens during microframe 212, the driver will
> not terminate the isochronous URB, because it is not scheduled to end
> yet.  But if an interrupt for a bulk URB happens during microframe 347,
> then the driver will terminate the isochronous URB, because that is
> after the scheduled end (which is microframe 340).
how about situation like below:
HW Frame index is located at microframe 90. And there was an
isochronous URB that was scheduled to transmit packets during
microframes 100, 180, 260, and 340.

Interrupt happen for Bulk when HW increase Frame index to 98.

After driver scan asynchronous schedule,  driver finds
ehci->isoc_count != 0 and start scan_isoc.
Isn't it possible that Driver may drop those previous scheduled
isochronous packets?

Appreciate your kind help,
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: some question about EXDEV status in period schedule

2013-12-01 Thread Alan Stern
On Sun, 1 Dec 2013, yoma sophian wrote:

> >> Suppose itds are submitted then ehci_work is triggered by bulk
> >> interrupt and ehci->isoc_count >0.
> >>
> >> The race condition may happen if hardware hasn't handled those itds, right?
> >
> > I don't know what race condition you are talking about.  Please explain
> > in more detail.
> 
> 1. submit iso urbs ehci->periodic_count ++
> 2. interrupt for bulk happen
> 3. scan async
> 4. scan iso schedule, since ehci->periodic_count != 0
> 5. clear urb if host hasn't enough time to handle it

This isn't a race condition, because the driver does not terminate
isochronous URBs before they are scheduled to end.

For example, suppose there was an isochronous URB that was scheduled to
transmit packets during microframes 100, 180, 260, and 340.  If an
interrupt for a bulk URB happens during microframe 212, the driver will
not terminate the isochronous URB, because it is not scheduled to end
yet.  But if an interrupt for a bulk URB happens during microframe 347,
then the driver will terminate the isochronous URB, because that is 
after the scheduled end (which is microframe 340).

> > If the periodic count has just dropped to 0, it's quite likely that the
> > periodic count will increase again in the near future.  Therefore the
> > driver leaves the periodic schedule running for a little while.  That's
> > better than stopping the schedule and starting it again a few
> > milliseconds later.
> 
> why in the previous kernel version, take v3.1-rc1 for example, turn
> off period schedule directly?

I don't know why; I didn't write that code in the earlier kernels.

> is there any bug then we change the turn
> off policy?

No, it was not a bug.  The new code is an improvement, that's all.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Re: some question about EXDEV status in period schedule

2013-11-24 Thread Alan Stern
On Sun, 24 Nov 2013, yoma sophian wrote:

> >> My questions are:
> >> 1. in usb driver,
> >>   ehci-sched.c --> itd_complete ->
> >>
> >>if (unlikely (t & ISO_ERRS)) {
> >> ..  (case A)
> >>} else if (likely ((t & EHCI_ISOC_ACTIVE) == 0)) {
> >>    (case b)
> >>} else {
> >>  /* URB was too late */(case c)
> >>   urb->error_count++;
> >> }
> >> EXDEV seems come from above comment  " /*URB was too late */"
> >> >
> 
> >> >> 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.
> 
> Could I said that case mean after the urb is actually _was_ scheduled,
> the hardware doesn't service it until timeout?

Yes, that's another way to describe the same thing.

> > 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
> 
> I am not quite understand what does "URB_ISO_ASAP flag causes it to be
> delayed" mean.

In your log, the URBs are normally scheduled at intervals of 80 uframes 
(which is the same as 10 ms).  On the first line above, we see that URB 
d8a80400 was scheduled to start in uframe 111.  On the third line, we 
see that URB d8a80800 was scheduled to start in uframe 191, which is 80 
uframes later.  But on the fifth line, we see that when d8a80400 was 
resubmitted, it was scheduled to start in uframe 319, not uframe 271 = 
191 + 80.  In other words, it was scheduled 319 - 271 = 48 uframes too 
late.

It was scheduled 48 uframes too late because the URB_ISO_ASAP flag was 
set.  If that flag wasn't set, the URB would have been scheduled for 
uframe 271.

> Does that mean the 2 ms remaining is caused by "URB_ISO_ASAP"?

No.  It was caused by something else.

> > 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).
> Would you please let my know why you think it shouldn't be more than 2ms?

See the definition of Isochronous Scheduling Threshold in Table 2-7 and 
Section 4.7.2.1 of the EHCI spec.  Its value cannot be much larger than 
8 uframes, so after rounding up, the delay should not be larger than 2 
ms.

> > If the device does not send data, the driver will go into case a.
> 
> Why If the device does not send data, the driver will go into case a. ?
> in case a, that mean host get any error from the data he recive.
> If no data get from device, how host determine the error from?

It is a Timeout error if the host controller does not receive a DATA
packet within a few microseconds of sending an IN packet.  The 
controller sets the XactErr bit in the iTD Transaction Status byte.  
See Table 3-3 in the EHCI spec.

> > The driver will go into case c if the hardware isn't working right.
> Howabout below race condition happen for accidentlly run into case C.
> 
> Actually in there are bulk/iso interleaving happening on my system.

Why aren't the bulk transfers in your usbmon log?

> Suppose itds are submitted then ehci_work is triggered by bulk
> interrupt and ehci->isoc_count >0.
> 
> The race condition may happen if hardware hasn't handled those itds, right?

I don't know what race condition you are talking about.  Please explain 
in more detail.

> BTW, why don't we just turn off period schedule in ehci_poll_PSS like below
> (since we turn it on directly in ehci_poll_PSS, right)
>   if (want == 0) {/* Stopped */
>   if (ehci->periodic_count > 0)
>   ehci_set_command_bit(ehci, CMD_PSE);
> 
>   } else {/* Running */
>   if (ehci->periodic_count == 0) {
> 
>   /* Turn off the schedule after a while */
> - ehci_enable_event(ehci, EHCI_HRTIMER_DISABLE_PERIODIC,
>

Re: some question about EXDEV status in period schedule

2013-11-24 Thread yoma sophian
2013/11/19 Alan Stern :
> Please use Reply-To-All so that your message gets sent to the mailing
> list as well as to me.
Sorry for forgetting that :)

>
> On Sat, 16 Nov 2013, yoma sophian wrote:
>
> hi alan:
>

>> My questions are:
>> 1. in usb driver,
>>   ehci-sched.c --> itd_complete ->
>>
>>if (unlikely (t & ISO_ERRS)) {
>> ..  (case A)
>>} else if (likely ((t & EHCI_ISOC_ACTIVE) == 0)) {
>>    (case b)
>>} else {
>>  /* URB was too late */(case c)
>>   urb->error_count++;
>> }
>> EXDEV seems come from above comment  " /*URB was too late */"
>> >

>> >> 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.

Could I said that case mean after the urb is actually _was_ scheduled,
the hardware doesn't service it until timeout?

>
>> >> 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.
>

>>
>> 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

I am not quite understand what does "URB_ISO_ASAP flag causes it to be
delayed" mean.
Does that mean the 2 ms remaining is caused by "URB_ISO_ASAP"?

> 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).
Would you please let my know why you think it shouldn't be more than 2ms?


>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.

Why If the device does not send data, the driver will go into case a. ?
in case a, that mean host get any error from the data he recive.
If no data get from device, how host determine the error from?


> 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 hardwa

Re: some question about EXDEV status in period schedule

2013-11-22 Thread yoma sophian
SORRY for send the wrong mail :)


2013/11/23 yoma sophian :
> 2013/11/19 Alan Stern :
>> 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 re

Re: some question about EXDEV status in period schedule

2013-11-18 Thread Alan Stern
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 w

Re: some question about EXDEV status in period schedule

2013-11-15 Thread Alan Stern
On Sat, 16 Nov 2013, yoma sophian wrote:

> hi all:
> When capturing audio through HS  webcam by iso protocol under my
> embedded system, I can hear the audio is not  continuous.

The problem is that sometimes the URBs don't get submitted soon enough.

> Then I check usb mon and i found sometime the return status will be
> EXDEV like below:
> (below is partial and detail log is attach in the mail)

I have shortened the lines to make the log easier to read:

> d8a81c00 99049439 C Zi:1:003:2 0:8:5535:0 10 0:0:96 0:512:96
> d8a81c00 99050046 S Zi:1:003:2 -115:8:0 10 -18:0:512 -18:512:512

Here URB d8a81c00 was resubmitted about 0.6 ms after it completed.  
That's normal.

> d8a81a00 99059580 C Zi:1:003:2 0:8:5615:0 10 0:0:100 0:512:100
> d8a81c00 99069328 C Zi:1:003:2 0:8:5695:0 10 0:0:100 0:512:100

And then it completed 19.3 ms after submission.  Again normal.

> d8a81a00 99078681 S Zi:1:003:2 -115:8:0 10 -18:0:512 -18:512:512

But here URB d8a81a00 wasn't resubmitted until 19.1 ms after it
completed.  The latency was more than 18 ms!  d8a81c00 completed at
timestamp 99069328, so d8a81a00 should have been resubmitted before
then.  But it wasn't; it was submitted about 10 ms too late.

> d8a81c00 99080252 S Zi:1:003:2 -115:8:0 10 -18:0:512 -18:512:512
> d8a81a00 99094075 C Zi:1:003:2 0:8:5887:10 10 -18:0:0 -18:512:0

d8a81a00 should have been scheduled for uframe 5775 (80 uframes after
d8a81c00).  Instead it was scheduled for uframe 5887, about 11 ms
later.  Probably the -EXDEV errors in the C line are because the device
stopped sending data.

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.

> 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.

> As far as I know,itd_complete is called "in irq handler" and
> "scan_work thread", and urb is already submitted in these 2 places.
> 
> 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".

> 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.

> 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.

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.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html