Laurent
> On Thursday 28 March 2013 06:48:09 B, Ravi wrote:
> > >> On Wednesday 27 March 2013 10:43:24 B, Ravi wrote:
> > >>> Hi
> > >>>
> > >>> I am observing issue while streaming video from usb camera connected
> to
> > >>> host controller based on mentor graphics. The issue is root caused
> that
> > >>> there are huge SOF gaps seen between the two isochronous IN token
> issued
> > >>> by host controller. This is due to fact, significant amount of time
> is
> > >>> spent in uvc callback function handler. Due to this next request
> > >>> programmed is delayed leads to this failure of video streaming. I
> have
> > >>> measured time taken by uvc callback function is in range minimum of
> 11
> > >>> microsecond to maximum of 3318 microsecond. Looks like callback
> handler
> > >>> doing some processing and takes more time to return rather than
> giveback
> > >>> immediately. Need your help to understand why uvc callback handler
> takes
> > >>> much time, if it does any processing can it move to different task
> > >>> context and return immediately, this will reduce the latency.
> > >>
> > >> I'm surprised by that large delay. A quick look at the UVC URB
> completion
> > >> handler (I assume you're talking about the host driver, not the
> gadget
> > >> driver)
> > >
> > > Thanks for reply, Yes, I am using the musb host controller driver
> > > (driver/usb/musb).
> > >
> > >> doesn't show any significant source of delay. You will likely need to
> > >> profile the code to find out where the problem comes from.
> > >
> > > I have profiled by adding timestamp before and after the
> > > usb_hcd_giveback_urb() @ drivers/usb/musb/musb_host.c and found the
> > > microsecond delay is ranging from 11usec to 3318usec while capturing
> video
> > > stream frames of resolution 640x480 from usb camera.
> > >
> > > static void musb_giveback(struct musb *musb, struct urb *urb, int
> status)
> > >
> > > __releases(musb->lock)
> > > __acquires(musb->lock)
> > > {
> > >
> > > + struct timeval st, et, t;
> > > + int is_isoc;
> > > .....
> > > + if (is_isoc)
> > > + do_gettimeofday(&st); /* get start time */
> > >
> > > usb_hcd_giveback_urb(musb_to_hcd(musb), urb, status);
> > >
> > > + if (is_isoc) {
> > > + do_gettimeofday(&et); /* get end time */
> > > + t.tv_sec = et.tv_sec - st.tv_sec;
> > > + t.tv_usec = et.tv_usec - st.tv_usec;
> > > + gtime[gIndex++ % MAX_LOG_TIME] = t; /* compute diff
> time
> > > */
> > > + }
> > >
> > > Anything I miss here?
> > >
> > >> You should also make sure that no other IRQ handler on the system
> keeps
> > >> IRQs disabled for a long time.
> >
> > Some more debugging, Most of the time spend in stream->decode() function
>
> That points to uvc_video_decode_isoc().
You are correct, that points to uvc_video_decode_isoc()
>
> > in uvc_video_complete() callback handler.
>
> It's not very surprising, but doesn't tell where the problem comes from.
> As
> Ming Lei pointed out, slow access to coherent memory might be an
> explanation.
> Could you find out how the time is spent between uvc_video_decode_start(),
> uvc_video_decode_data() and uvc_video_decode_data() ? It might also be
> worth
> it timing the uvc_queue_next_buffer() calls, in case the function is
> delayed
> by spinlock contention (if you're running on an SMP system).
I did not dig further, I try to get this timing info.
Quickly I tried another experiment, instead of calling stream->decode() in callback, initiated work thread, which perform stream->decode() & re-submit urb. This reduces the uvc_video_callback() time to 12usec, But after 900 urb completion, submit_urb() failed with -EBUSY error. Further I stopped debugging, something I may not be doing right at uvc level.
Thanks Laurent.
Regards
Ravi B
--
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
