I've just found that dma->actual_len equals to zero in most cases at musb_host.c line 1946. And this produces zero-length packages. http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/tree/drivers/usb/musb/musb_host.c#n1946 Any ideas why? 2016-08-04 19:57 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: > I've just found that many packages in URBs have zero actual_length (It > is a question why). > Then the following end of frame criteria leads to `frame underflow' message: > > if (flen < pdev->vlast_packet_size) { > /* Shorter packet... end of frame */ > if (pdev->vsync == 2) > pwc_frame_complete(pdev); > if (pdev->fill_buf == NULL) > pdev->fill_buf = pwc_get_next_fill_buf(pdev); > if (pdev->fill_buf) { > pdev->fill_buf->filled = 0; > pdev->vsync = 1; > } > } > > 2016-08-01 21:16 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: >> pwc module output with trace=511 is the following: >> >> [ 24.793109] usbcore: registered new interface driver Philips webcam >> [ 29.276979] pwc: Unsupported pixel format >> [ 29.277055] pwc: pwc_vidioc_fill_fmt() width=640, height=480, >> bytesperline=640, sizeimage=460800, pixelformat=YU12 >> [ 29.277090] pwc: Trying to set format to: width=640 height=480 >> fps=15 format=YU12 >> [ 29.277123] pwc: set_video_mode(640x480 @ 30, pixfmt 32315559). >> [ 29.277145] pwc: decode_size = 5. >> [ 29.277180] pwc: frame_size=63120, vframes=15, vsize=5, vbandlength=526 >> [ 29.277204] pwc: Set resolution to 640x480 >> [ 29.277225] pwc: pwc_set_video_mode(), return=0 >> [ 29.277256] pwc: pwc_vidioc_fill_fmt() width=640, height=480, >> bytesperline=640, sizeimage=460800, pixelformat=YU12 >> [ 29.277306] pwc: ioctl(VIDIOC_G_FMT) return size 640x480 >> [ 29.277337] pwc: pwc_vidioc_fill_fmt() width=640, height=480, >> bytesperline=640, sizeimage=460800, pixelformat=YU12 >> [ 29.277449] pwc: set_video_mode(640x480 @ 10, pixfmt 32315559). >> [ 29.277475] pwc: decode_size = 5. >> [ 29.278726] pwc: frame_size=94560, vframes=10, vsize=5, vbandlength=788 >> [ 29.278750] pwc: Set resolution to 640x480 >> [ 29.300374] pwc: set_video_mode(640x480 @ 10, pixfmt 32315559). >> [ 29.300420] pwc: decode_size = 5. >> [ 29.441759] pwc: frame_size=94560, vframes=10, vsize=5, vbandlength=788 >> [ 29.441792] pwc: Set resolution to 640x480 >> [ 29.441824] pwc: Setting alternate interface 9 >> [ 29.455061] pwc: Allocated URB at 0xc9b83600 >> [ 29.455850] pwc: Allocated URB at 0xc9b83400 >> [ 29.456040] pwc: Allocated URB at 0xc9b83200 >> [ 29.456271] pwc: URB 0xc9b83600 submitted. >> [ 29.456310] pwc: URB 0xc9b83400 submitted. >> [ 29.456341] pwc: URB 0xc9b83200 submitted. >> [ 29.456362] pwc: << pwc_isoc_init() >> [ 30.078550] pwc: Frame buffer underflow (20076 bytes); discarded. >> [ 30.170543] pwc: Frame buffer underflow (12428 bytes); discarded. >> [ 30.272538] pwc: Frame buffer underflow (14340 bytes); discarded. >> [ 30.374541] pwc: Frame buffer underflow (16252 bytes); discarded. >> [ 30.476535] pwc: Frame buffer underflow (18164 bytes); discarded. >> [ 30.578532] pwc: Frame buffer underflow (20076 bytes); discarded. >> [ 30.670538] pwc: Frame buffer underflow (12428 bytes); discarded. >> [ 30.772544] pwc: Frame buffer underflow (14340 bytes); discarded. >> [ 30.874547] pwc: Frame buffer underflow (16252 bytes); discarded. >> [ 30.976552] pwc: Frame buffer underflow (18164 bytes); discarded. >> [ 31.078536] pwc: Frame buffer underflow (20076 bytes); discarded. >> [ 31.170533] pwc: Frame buffer underflow (12428 bytes); discarded. >> [ 31.272549] pwc: Frame buffer underflow (14340 bytes); discarded. >> [ 31.374545] pwc: Frame buffer underflow (16252 bytes); discarded. >> [ 31.476537] pwc: Frame buffer underflow (18164 bytes); discarded. >> [ 31.578536] pwc: Frame buffer underflow (20076 bytes); discarded. >> [ 31.660895] pwc: Frame buffer underflow (11472 bytes); discarded. >> [ 31.772554] pwc: Frame buffer underflow (14340 bytes); discarded. >> [ 31.874548] pwc: Frame buffer underflow (16252 bytes); discarded. >> [ 31.976533] pwc: Frame buffer underflow (18164 bytes); discarded. >> >> >> 2016-07-31 23:31 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: >>> Hello, >>> >>> I've also just found that the same commit breaks cpufreq on BeagleBone Black :) >>> >>> So, probably without HCD_BH flag musb works correctly only at 1Ghz CPU >>> frequency, which is unlisted and being set to 720Mhz by cpufreq driver >>> (as it did whet there was cpufreq driver). >>> >>> 2016-07-29 21:01 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: >>>> Hello, >>>> >>>> I've found that the following commit fixes the issue: >>>> >>>> commit 7694ca6e1d6f01122f05039b81f70f64b1ec4063 >>>> Author: Viresh Kumar <viresh.kumar@xxxxxxxxxx> >>>> Date: Fri Apr 22 16:58:42 2016 +0530 >>>> >>>> cpufreq: omap: Use generic platdev driver >>>> >>>> The cpufreq-dt-platdev driver supports creation of cpufreq-dt platform >>>> device now, reuse that and remove similar code from platform code. >>>> >>>> >>>> 2016-07-28 19:16 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: >>>>> Hello, >>>>> >>>>> I've just bisected commit, which fixed the issue in v4.7 >>>>> >>>>> commit 9fa64d6424adabf0e3a546ae24d01a62a927b342 >>>>> Merge: f55532a febce40 >>>>> Author: Rafael J. Wysocki <rafael.j.wysocki@xxxxxxxxx> >>>>> Date: Sat Apr 2 01:07:17 2016 +0200 >>>>> >>>>> Merge back intel_pstate fixes for v4.6. >>>>> >>>>> * pm-cpufreq: >>>>> intel_pstate: Avoid extra invocation of intel_pstate_sample() >>>>> intel_pstate: Do not set utilization update hook too early >>>>> >>>>> Unfortunately, intel_pstate branch doesn't have >>>>> f551e13529833e052f75ec628a8af7b034af20f9 applied. >>>>> I'll try to bisect this branch with the patch manually applied. >>>>> >>>>> 2016-07-27 20:34 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: >>>>>> Hello, >>>>>> >>>>>> I've just biseced commit, which introduced this issue >>>>>> >>>>>> commit f551e13529833e052f75ec628a8af7b034af20f9 >>>>>> Author: Bin Liu <b-liu@xxxxxx> >>>>>> Date: Mon Apr 25 15:53:30 2016 -0500 >>>>>> >>>>>> Revert "usb: musb: musb_host: Enable HCD_BH flag to handle urb >>>>>> return in bottom half" >>>>>> >>>>>> I have not checked yet, if it was intentionnaly fixed. >>>>>> >>>>>> 2016-07-23 22:24 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: >>>>>>> 2016-07-20 21:56 GMT+03:00 Matwey V. Kornilov <matwey@xxxxxxxxxx>: >>>>>>>> 2016-07-20 18:06 GMT+03:00 Bin Liu <b-liu@xxxxxx>: >>>>>>>>> Hi, >>>>>>>>> >>>>>>>>> On Wed, Jul 20, 2016 at 05:44:56PM +0300, Matwey V. Kornilov wrote: >>>>>>>>>> 2016-07-20 17:13 GMT+03:00 Bin Liu <b-liu@xxxxxx>: >>>>>>>>>> > Hi, >>>>>>>>>> > >>>>>>>>>> > On Wed, Jul 20, 2016 at 09:09:42AM +0300, Matwey V. Kornilov wrote: >>>>>>>>>> >> 2016-07-20 0:34 GMT+03:00 Bin Liu <b-liu@xxxxxx>: >>>>>>>>>> >> > Hi, >>>>>>>>>> >> > >>>>>>>>>> >> > On Wed, Jul 20, 2016 at 12:25:44AM +0300, Matwey V. Kornilov wrote: >>>>>>>>>> >> >> 2016-07-19 23:56 GMT+03:00 Bin Liu <b-liu@xxxxxx>: >>>>>>>>>> >> >> > Hi, >>>>>>>>>> >> >> > >>>>>>>>>> >> >> > On Tue, Jul 19, 2016 at 11:21:17PM +0300, matwey@xxxxxxxxxx wrote: >>>>>>>>>> >> >> >> Hello, >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> I have Philips SPC 900 camera (0471:0329) connected to my AM335x based BeagleBoneBlack SBC. >>>>>>>>>> >> >> >> I am sure that both of them are fine and work properly. >>>>>>>>>> >> >> >> I am running Linux 4.6.4 (my kernel config is available at https://clck.ru/A2kQs ) and I've just discovered, that there is an issue with frame transfer when high resolution formats are used. >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> The issue is the following. I use simple v4l2 example tool (taken from API docs), which source code is available at http://pastebin.com/grcNXxfe >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> When I use (see line 488) 640x480 frames >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> fmt.fmt.pix.width = 640; >>>>>>>>>> >> >> >> fmt.fmt.pix.height = 480; >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> then I get "select timeout" and don't get any frames. >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> When I use 320x240 frames >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> fmt.fmt.pix.width = 320; >>>>>>>>>> >> >> >> fmt.fmt.pix.height = 240; >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> then about 60% frames are missed. An example outpout of ./a.out -f is available at https://yadi.sk/d/aRka8xWPtSc4y >>>>>>>>>> >> >> >> It looks like there are pauses between bulks of frames (frame counter and timestamp as returned from v4l2 API): >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> 3 3705.142553 >>>>>>>>>> >> >> >> 8 3705.342533 >>>>>>>>>> >> >> >> 13 3705.542517 >>>>>>>>>> >> >> >> 110 3708.776208 >>>>>>>>>> >> >> >> 115 3708.976190 >>>>>>>>>> >> >> >> 120 3709.176169 >>>>>>>>>> >> >> >> 125 3709.376152 >>>>>>>>>> >> >> >> 130 3709.576144 >>>>>>>>>> >> >> >> 226 3712.807848 >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> When I use tiny 160x120 frames >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> fmt.fmt.pix.width = 160; >>>>>>>>>> >> >> >> fmt.fmt.pix.height = 120; >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> then more frames are received. See output example at https://yadi.sk/d/DedBmH6ftSc9t >>>>>>>>>> >> >> >> That is why I thought that everything was fine in May when used tiny xawtv window to check kernel OOPS presence (see http://www.spinics.net/lists/linux-usb/msg141188.html for reference) >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> Even more. When I introduce USB hub between the host and the webcam, I can not receive even any 320x240 frames. >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> I've managed to use ftrace to see what is going on when no frames are received. >>>>>>>>>> >> >> >> I've found that pwc_isoc_handler is called frequently as the following: >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> 0) | pwc_isoc_handler [pwc]() { >>>>>>>>>> >> >> >> 0) | usb_submit_urb [usbcore]() { >>>>>>>>>> >> >> >> 0) | usb_submit_urb.part.3 [usbcore]() { >>>>>>>>>> >> >> >> 0) | usb_hcd_submit_urb [usbcore]() { >>>>>>>>>> >> >> >> 0) 0.834 us | usb_get_urb [usbcore](); >>>>>>>>>> >> >> >> 0) | musb_map_urb_for_dma [musb_hdrc]() { >>>>>>>>>> >> >> >> 0) 0.792 us | usb_hcd_map_urb_for_dma [usbcore](); >>>>>>>>>> >> >> >> 0) 5.750 us | } >>>>>>>>>> >> >> >> 0) | musb_urb_enqueue [musb_hdrc]() { >>>>>>>>>> >> >> >> 0) 0.750 us | _raw_spin_lock_irqsave(); >>>>>>>>>> >> >> >> 0) | usb_hcd_link_urb_to_ep [usbcore]() { >>>>>>>>>> >> >> >> 0) 0.792 us | _raw_spin_lock(); >>>>>>>>>> >> >> >> 0) 0.791 us | _raw_spin_unlock(); >>>>>>>>>> >> >> >> 0) + 10.500 us | } >>>>>>>>>> >> >> >> 0) 0.791 us | _raw_spin_unlock_irqrestore(); >>>>>>>>>> >> >> >> 0) + 25.375 us | } >>>>>>>>>> >> >> >> 0) + 45.208 us | } >>>>>>>>>> >> >> >> 0) + 51.042 us | } >>>>>>>>>> >> >> >> 0) + 56.084 us | } >>>>>>>>>> >> >> >> 0) + 61.292 us | } >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> However, pwc_isoc_handler never calls vb2_buffer_done() that is why I get "select timeout" in userspace. >>>>>>>>>> >> >> >> Unfortunately, my kernel is not compiled with CONFIG_USB_PWC_DEBUG=y but I can recompile it, if you think that it could provide more information. I am also ready to perform additional tests (use usbmon maybe?). >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> How could this issue be resolved? >>>>>>>>>> >> >> >> >>>>>>>>>> >> >> >> Thank you. >>>>>>>>>> >> >> > >>>>>>>>>> >> >> > Do you have CPPI DMA enabled? If so I think you might hit on a known >>>>>>>>>> >> >> > issue in CPPI Isoch transfer, in which the MUSB controller only sends IN >>>>>>>>>> >> >> > tokens in every other SOF, so only half of the bus bandwidth is >>>>>>>>>> >> >> > utilized, which causes video frame drops in higher resolution. >>>>>>>>>> >> >> > >>>>>>>>>> >> >> >>>>>>>>>> >> >> Yes, I do use DMA: >>>>>>>>>> >> >> >>>>>>>>>> >> >> CONFIG_USB_TI_CPPI41_DMA=y >>>>>>>>>> >> > >>>>>>>>>> >> > Okay. >>>>>>>>>> >> > >>>>>>>>>> >> >> >>>>>>>>>> >> >> > To confirm this, use a bus analyzer to capture a bus trace, you would >>>>>>>>>> >> >> > see no IN tokens in every other SOF while transfering Isoch packets. >>>>>>>>>> >> >> > >>>>>>>>>> >> >> >>>>>>>>>> >> >> I am sorry, I am new to USB debugging. Do you mean I need to use >>>>>>>>>> >> >> usbmon or some external hardware device? >>>>>>>>>> >> > >>>>>>>>>> >> > I barely use usbmon, and not sure if it gives the information I am >>>>>>>>>> >> > looking for. But I meant the external test equipment - USB bus protocol >>>>>>>>>> >> > analyzer - a bus packet sniffer. >>>>>>>>>> >> > >>>>>>>>>> >> >>>>>>>>>> >> Now I see. I've googled it, they start from $1000, I don't know >>>>>>>>>> >> when/whether/where I can get one to try. >>>>>>>>>> > >>>>>>>>>> > I think you might be able to check it without a sniffer - MUSB >>>>>>>>>> > controller can generate SOF interrupts, but it is masked in current >>>>>>>>>> > driver. So I think you could enable SOF interrupt, then if you get a log >>>>>>>>>> > as >>>>>>>>>> > SOF >>>>>>>>>> > rx packet >>>>>>>>>> > SOF >>>>>>>>>> > rx packet >>>>>>>>>> > SOF >>>>>>>>>> > ... >>>>>>>>>> > or >>>>>>>>>> > SOF >>>>>>>>>> > rx packet >>>>>>>>>> > rx packet >>>>>>>>>> > rx packet >>>>>>>>>> > SOF >>>>>>>>>> > rx packet >>>>>>>>>> > rx packet >>>>>>>>>> > rx packet >>>>>>>>>> > SOF >>>>>>>>>> > ... >>>>>>>>>> > >>>>>>>>>> > which means your issue is different from the one I mentioned. But if >>>>>>>>>> > you get a log as >>>>>>>>>> > >>>>>>>>>> > SOF >>>>>>>>>> > rx packet >>>>>>>>>> > SOF >>>>>>>>>> > SOF <--- no rx packets in two consecutive SOFs >>>>>>>>>> > rx packet >>>>>>>>>> > SOF >>>>>>>>>> > SOF >>>>>>>>>> > >>>>>>>>>> > then you hit on the known issue I mentioned. >>>>>>>>>> > >>>>>>>>>> >> Until that, could I check something else? For instance, disable >>>>>>>>>> >> CONFIG_USB_TI_CPPI41_DMA. >>>>>>>>>> > >>>>>>>>>> > You could disable it, but I don't think you will get yuv video stream >>>>>>>>>> > of 640x480@30fps. PIO mode does not support such high bandwidth. What is >>>>>>>>>> > your video requirement anyway? >>>>>>>>>> >>>>>>>>>> Many thanks for your guidance. I will answer the rest later when will >>>>>>>>>> be ready to play with SOF interrupt. >>>>>>>>>> Now, I would like to say that use_dma=0 doesn't change the behaviour: >>>>>>>>>> >>>>>>>>>> # cat /sys/module/musb_hdrc/parameters/use_dma >>>>>>>>>> N >>>>>>>>> >>>>>>>>> It sounds like you have a different issue here. With usb_dma=0, I >>>>>>>>> remembered I can get 320x240 YUV stream @30fps from uvc cameras. >>>>>>>>> >>>>>>>>>> >>>>>>>>>> I would like 640x480@5fps which works with x86 based PC. Issue here, >>>>>>>>>> that I can not obtain 640x480 at any FPS on musb. >>>>>>>>> >>>>>>>>> The current CPPI41 driver should be able to handle this. I think you >>>>>>>>> really have to debug the pwc driver to figure out why it drops the video >>>>>>>>> frame. I personally don't have a pwc supported camera, never looked the >>>>>>>>> pwc driver... >>>>>>>> >>>>>>>> Surprisingly, I've found that my 10-year-old laptop (Intel Core Solo >>>>>>>> T1350) has the similar issue with pwc (kernel 3.16). It drops 80% of >>>>>>>> 640x480 frames. >>>>>>>> Vortex86 200Mhz based rugged PC with 2.6.14 works fine. >>>>>>>> Quad-code Atom E3800 based PC with 4.1 also works fine. >>>>>>>> >>>>>>>> So, I even don't know what to say. Probably, the issue depends on CPU >>>>>>>> latency/performance and it was there for a while. >>>>>>>> Fortunately, I think, I could use git bisect if I found latest forking >>>>>>>> kernel for my laptop. >>>>>>>> >>>>>>> >>>>>>> It seems that the issue is gone in 4.7-rc7, so forget it. >>>>>>> >>>>>>>>> >>>>>>>>>> >>>>>>>>>> > >>>>>>>>>> >> >>>>>>>>>> >> I've found that after hours of transmit, the camera stops iso at all >>>>>>>>>> >> (until reset). Maybe its brain becomes damaged by the transfer issues >>>>>>>>>> > >>>>>>>>>> > How did you check that? MUSB stopped generating RX EP interrupt? >>>>>>>>>> >>>>>>>>>> Something like that, I suppose. Normally, I see input data flow in >>>>>>>>>> usbmon, but don't see frames in v4l2. >>>>>>>>>> But when camera 'hungs', I don't see nor input flow (except the >>>>>>>>>> control packages exchange) neither frames. >>>>>>>>> >>>>>>>>> Fair enough. >>>>>>>>> >>>>>>>>> Regards, >>>>>>>>> -Bin. >>>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> -- >>>>>>>> With best regards, >>>>>>>> Matwey V. Kornilov. >>>>>>>> Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia >>>>>>>> 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 >>>>>>> >>>>>>> >>>>>>> >>>>>>> -- >>>>>>> With best regards, >>>>>>> Matwey V. Kornilov. >>>>>>> Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia >>>>>>> 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 >>>>>> >>>>>> >>>>>> >>>>>> -- >>>>>> With best regards, >>>>>> Matwey V. Kornilov. >>>>>> Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia >>>>>> 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 >>>>> >>>>> >>>>> >>>>> -- >>>>> With best regards, >>>>> Matwey V. Kornilov. >>>>> Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia >>>>> 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 >>>> >>>> >>>> >>>> -- >>>> With best regards, >>>> Matwey V. Kornilov. >>>> Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia >>>> 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 >>> >>> >>> >>> -- >>> With best regards, >>> Matwey V. Kornilov. >>> Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia >>> 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 >> >> >> >> -- >> With best regards, >> Matwey V. Kornilov. >> Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia >> 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 > > > > -- > With best regards, > Matwey V. Kornilov. > Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia > 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 -- With best regards, Matwey V. Kornilov. Sternberg Astronomical Institute, Lomonosov Moscow State University, Russia 119991, Moscow, Universitetsky pr-k 13, +7 (495) 9392382 -- 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
