Dears,
it seems the attached file is fail to linux-usb. I copy the content
from file below:
==================================================================
USB mon log:
81631c00 1943532448 C Zi:1:002:1 0:1:3567:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
S------>81631c00 1943532448 S Zi:1:002:1 -150:1:3567 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631800 1943542448 C Zi:1:002:1 0:1:3599:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
81631800 1943542448 S Zi:1:002:1 -150:1:3599 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631400 1943542448 C Zi:1:002:1 0:1:3631:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
81631400 1943542448 S Zi:1:002:1 -150:1:3631 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631000 1943542448 C Zi:1:002:1 0:1:3663:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
81631000 1943542448 S Zi:1:002:1 -150:1:3663 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81ba2c00 1943552448 C Zi:1:002:1 0:1:3695:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
81ba2c00 1943552448 S Zi:1:002:1 -150:1:3695 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631c00 1943552448 C Zi:1:002:1 0:1:3727:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
S------->81631c00 1943552448 S Zi:1:002:1 -150:1:3727 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631800 1943562448 C Zi:1:002:1 0:1:3759:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
81631800 1943562448 S Zi:1:002:1 -150:1:3759 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631400 1943562448 C Zi:1:002:1 0:1:3791:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
81631400 1943562448 S Zi:1:002:1 -150:1:3791 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631000 1943562448 C Zi:1:002:1 0:1:3823:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 384 D
81631000 1943562448 S Zi:1:002:1 -150:1:3823 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81ba2c00 1943582448 C Zi:1:002:1 0:1:3855:0 32 0:0:12
0:3072:12 0:6144:12 0:9216:12 0:12288:12 3420 D
81ba2c00 1943582448 S Zi:1:002:1 -150:1:3855 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
C------->81631c00 1943582448 C Zi:1:002:1 0:1:3887:0 32 0:0:12
0:3072:1024 0:6144:1024 0:9216:12 0:12288:1024 21636 D
81631c00 1943582448 S Zi:1:002:1 -150:1:3887 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631800 1943582448 C Zi:1:002:1 0:1:3919:0 32 0:0:12
0:3072:1024 0:6144:1024 0:9216:12 0:12288:1024 21636 D
81631800 1943582448 S Zi:1:002:1 -150:1:3919 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631400 1943582448 C Zi:1:002:1 0:1:3951:0 32 0:0:1024
0:3072:1024 0:6144:12 0:9216:1024 0:12288:1024 24672 D
81631400 1943582448 S Zi:1:002:1 -150:1:3951 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631000 1943582448 C Zi:1:002:1 0:1:3983:0 32 0:0:1024
0:3072:12 0:6144:1024 0:9216:1024 0:12288:12 24672 D
81631000 1943582448 S Zi:1:002:1 -150:1:3983 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81ba2c00 1943582448 C Zi:1:002:1 0:1:4015:0 32 -18:0:0
-18:3072:0 -18:6144:0 -18:9216:0 -18:12288:0 0
81ba2c00 1943582448 S Zi:1:002:1 -150:1:4015 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631c00 1943582448 C Zi:1:002:1 0:1:4047:0 32 -18:0:0
-18:3072:0 -18:6144:0 -18:9216:0 -18:12288:0 0
81631c00 1943582448 S Zi:1:002:1 -150:1:4047 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631c00 0 E Zi:0:002:1 -27 0
81631800 1943582448 C Zi:1:002:1 0:1:4079:0 32 -18:0:0
-18:3072:0 -18:6144:0 -18:9216:0 -18:12288:0 0
81631800 1943582448 S Zi:1:002:1 -150:1:4079 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
81631400 1943582448 C Zi:1:002:1 0:1:15:0 32 -18:0:0
-18:3072:0 -18:6144:0 -18:9216:0 -18:12288:0 0
81631400 1943582448 S Zi:1:002:1 -150:1:15 32 -18:0:3072
-18:3072:3072 -18:6144:3072 -18:9216:3072 -18:12288:3072 98304 <
==========================================================================================================
the error log from console:
[1943582448] iso_stream_schedule:line=1514, request 81631c00 would
overflow (3924+31 >= 3936)
[1943582448] iso_stream_schedule
[1943582448] mod=4096, span=32
[1943582448] now=283
[1943582448] start=4207
[1943582448] next=283
[1943582448] period=1
[1943582448] excess=3923
[1943582448] stream->next_uframe=111
[1943582448] uvcvideo: Failed to resubmit video URB (-27).
[1943592448] iso_stream_schedule:line=1514, request 81631800 would
overflow (3908+31 >= 3936)
[1943592448] iso_stream_schedule
[1943592448] mod=4096, span=32
[1943592448] now=1195
[1943592448] start=5103
[1943592448] next=1195
[1943592448] period=1
[1943592448] excess=3907
[1943592448] stream->next_uframe=1007
[1943592448] uvcvideo: Failed to resubmit video URB (-27).
[1943692448] iso_stream_schedule:line=1514, request 81ba2c00 would
overflow (3926+31 >= 3936)
[1943692448] iso_stream_schedule
[1943692448] mod=4096, span=32
[1943692448] now=2777
[1943692448] start=6703
[1943692448] next=2777
[1943692448] period=1
[1943692448] excess=3925
[1943692448] stream->next_uframe=2607
[1943692448] uvcvideo: Failed to resubmit video URB (-27).
[1943792448] iso_stream_schedule:line=1514, request 81631400 would
overflow (3924+31 >= 3936)
[1943792448] iso_stream_schedule
[1943792448] mod=4096, span=32
[1943792448] now=283
[1943792448] start=4207
[1943792448] next=283
[1943792448] period=1
[1943792448] excess=3923
[1943792448] stream->next_uframe=111
[1943792448] uvcvideo: Failed to resubmit video URB (-27).
[1943892448] iso_stream_schedule:line=1514, request 81631000 would
overflow (3923+31 >= 3936)
[1943892448] iso_stream_schedule
[1943892448] mod=4096, span=32
[1943892448] now=1884
[1943892448] start=5807
[1943892448] next=1884
[1943892448] period=1
[1943892448] excess=3922
[1943892448] stream->next_uframe=1711
[1943892448] uvcvideo: Failed to resubmit video URB (-27).
=================================================================================
2011/5/30 Soho Soho123 <soho123.2012@xxxxxxxxx>:
> Dears,
>
>
> The attached is the log from USB mon, and error log. We have question
> about period of uvc driver submit urb.
> in 1.mon_2.out is USB Mon output log, line 8120 is the latest normal
> urb submit, line 8129 is the urb complete after 30 ms.
> in 0530_2log is the output message from console.
> From the output of USB mon, we can see the normally 20ms is period for
> uvc submit urb.
> But when the period is not 20 ms, then ehci host driver will return error.
> Could you kindly help to explain form detail for the mechanism in echi
> ISO schedule?
> We still do not get the point about ehci iso schedule checking criterion.
> 20ms may critical in our embedded system , since usb and wifi will
> share CPU simultaneously. If WiFi is not transmit smoothly, then WiFi
> driver will re-try. Such that USB may not service in at once.
>
> Thanks!
>
> Best Regards,
> Soho
>
> 2011/5/26 Alan Stern <stern@xxxxxxxxxxxxxxxxxxx>:
>> On Thu, 26 May 2011, Soho Soho123 wrote:
>>
>>> Dears,
>>>
>>> let me describe the detail about my testing:
>>> Stream Server is MJPG-Streamer
>>> ================================================================
>>> A.
>>> Using linux 2.6.30 kernel do the testing, and DO NOT update linux usb
>>> subsystem code (usb core , usb host driver), and DO NOT update UVC
>>> driver
>>>
>>> RESULT: IP Cam stream can work over night
>>
>> This is because the code in 2.6.30 is buggy. It should have stopped
>> with an error, but it didn't.
>>
>>> ------------------------------------------------------------------------------------------------------------------------------
>>> B.
>>> Using Linux 2.6.30 kernel do the testing, and Update linux usb
>>> subsystem code up to linux 2.6.39 (include the patch that I have
>>> mentioned) and DO NOT update UVC driver
>>>
>>> RESULT: IP cam stream can work for a few minutes only, then UVC driver
>>> will get submit urb error (-27) , error message list below:
>>> # [ 1067.188000] iso_stream_schedule:line=1514, request 812acc00 would
>>> overflow (3914+31 >= 3936)
>>> [ 1067.188000] uvcvideo: Failed to resubmit video URB (-27).
>>> [ 1067.192000] iso_stream_schedule:line=1514, request 8145bc00 would
>>> overflow (3917+31 >= 3936)
>>> [ 1067.192000] uvcvideo: Failed to resubmit video URB (-27).
>>> [ 1067.292000] iso_stream_schedule:line=1514, request 81769000 would
>>> overflow (3919+31 >= 3936)
>>> [ 1067.292000] uvcvideo: Failed to resubmit video URB (-27).
>>> [ 1067.392000] iso_stream_schedule:line=1514, request 81769400 would
>>> overflow (3918+31 >= 3936)
>>> [ 1067.392000] uvcvideo: Failed to resubmit video URB (-27).
>>> [ 1067.492000] iso_stream_schedule:line=1514, request 81769800 would
>>> overflow (3917+31 >= 3936)
>>> [ 1067.492000] uvcvideo: Failed to resubmit video URB (-27).
>>
>> This happens because the uvcvideo driver is falling behind. It is
>> submitting new isochronous URBs too late -- more than 20 ms after the
>> previuos isochronous URB finished.
>>
>>> -------------------------------------------------------------------------------------------------------------------------------
>>> C.
>>> Using Linux 2.6.30 kernel do the testing, and Update linux usb
>>> subsystem code up to linux 2.6.39 (include the patch that I have
>>> mentioned) and Update UVC driver, we modify the number of URBs in
>>> vuvcideo.h
>>> UVC_URBS 5
>>> to
>>> UVC_URBS 20
>>>
>>> RESULT: IP cam stream can work for over night, but there is some urb
>>> submit error occur. The stream can keep working even the urb submit
>>> error.
>>
>> This is because now there is more room for latency. The real problem
>> is that uvcvideo needs to submit new URBs periodically, but on your
>> system it was delayed by 20 ms. In other words, something on your
>> system is causing interrupt latencies that are several tens of
>> milliseconds.
>>
>>> ================================================================
>>> We would like to figure out the reason about new usb subsystem code
>>> need more UVC_URB for working long time.Coule you provide the hints
>>> for us, such that we can go in depth for tracing the flow in ehci iso
>>> schedule scheme?
>>
>>
>>> the error log is :
>>> ==========================================================
>>> 474.348000] iso_stream_schedule:line=1514, request 8176bc00 would overflow (3936+31 >= 3936)
>>> [ 474.348000] iso_stream_schedule
>>> [ 474.348000] mod=4096, sched->span=32
>>
>> You should look at span, not sched->span. You should also look at
>> stream->next_uframe.
>>
>>> [ 474.348000] now=773
>>> [ 474.348000] start=4709
>>> [ 474.348000] next=773
>>> [ 474.348000] period=1
>>> [ 474.348000] uvcvideo: Failed to resubmit video URB (-27).
>>> [ 474.352000] iso_stream_schedule:line=1514, request 8176b000 would overflow (3932+31 >= 3936)
>>> [ 474.352000] iso_stream_schedule
>>> [ 474.352000] mod=4096, sched->span=32
>>> [ 474.352000] now=784
>>> [ 474.352000] start=4716
>>> [ 474.352000] next=784
>>> [ 474.352000] period=1
>>> [ 474.352000] uvcvideo: Failed to resubmit video URB (-27).
>>> ==========================================================
>>> it seems the index of schedule list is corrupt, right?
>>
>> No. The schedule list is correct.
>>
>> In iso_stream_schedule(), "now" is the current microframe, and "next"
>> is the earliest microframe a new URB can be added to. "mod" is the
>> length of the schedule.
>>
>> You didn't print out the value of "excess", but I figure it was 3935
>> for the first URB and 3931 for the second. "excess" is the how many
>> microframes will pass before the currently scheduled URBs are finished.
>> Values greater than 4096 - 160 = 3936 are taken to be negative numbers
>> modulo 4096 (i.e., they indicate the currently scheduled URBs are
>> _already_ finished).
>>
>> In your case, it looks like the currently scheduled URBs are indeed
>> already finished, but more than 160 microframes ago since 3935 and
>> 3931 are both less than 3936.
>>
>> Alan Stern
>>
>>
>
--
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
