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