After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 732326 - v4l2: slow UVC webcam startup due to excessive S_FMT
v4l2: slow UVC webcam startup due to excessive S_FMT
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gst-plugins-good
git master
Other Linux
: Normal normal
: 1.3.91
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2014-06-27 10:35 UTC by Daniel Drake
Modified: 2014-07-04 12:57 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
v4l2object: drop workaround for misbehaving TRY_FMT (2.42 KB, patch)
2014-06-27 10:39 UTC, Daniel Drake
committed Details | Review
v4l2object: drop workaround for misbehaving TRY_FMT (5.63 KB, patch)
2014-07-01 12:22 UTC, Daniel Drake
rejected Details | Review

Description Daniel Drake 2014-06-27 10:35:09 UTC
gstreamer-0.8 and gstreamer-1.2 can start up my UVC webcam reasonably quickly, but with gstreamer-1.3 from git, "gst-launch-1.0 v4l2src ! xvimagesink" takes about 5 seconds before the video feed is displayed.
cheese takes 10 seconds to load, for some reason it seems to create the v4l2 object twice so the delay is doubled.

Device is branded as Manhattan 460729:

  idVendor           0x1e4e Cubeternet
  idProduct          0x0102 GL-UPC822 UVC WebCam
  bcdDevice            0.02
  iManufacturer           1 Etron Technology, Inc.
  iProduct                2 USB2.0 Camera

The delay is under gst_v4l2_object_get_caps() - in gstreamer1.3 on this setup this results in 25 S_FMT ioctls being dispatched from gst_v4l2_object_get_nearest_size which is called in nested loops via this call chain:

gst_v4l2_object_get_caps
gst_v4l2_object_probe_caps_for_format
gst_v4l2_object_probe_caps_for_format_and_size
gst_v4l2_object_get_nearest_size

The ioctl in question:
  if (prevfmt_valid)
    if (v4l2_ioctl (fd, VIDIOC_S_FMT, &prevfmt) < 0) {
      GST_WARNING_OBJECT (v4l2object->element,
          "Unable to restore format after trying format: %s",
          g_strerror (errno));
    }


This ioctl takes about 0.17 seconds per call.

The ioctl in question is a workaround of a kernel driver bug from 2011, see:
https://bugzilla.kernel.org/show_bug.cgi?id=36152
https://bugzilla.gnome.org/show_bug.cgi?id=649067

The kernel bug is closed upstream and I ran the test case, the earlier problem does not reproduce here.

Can we drop the workaround?
Comment 1 Daniel Drake 2014-06-27 10:39:11 UTC
Created attachment 279374 [details] [review]
v4l2object: drop workaround for misbehaving TRY_FMT

This workaround from 2011 was causing 25 S_FMT ioctls to be sent
to my UVC webcam from under gst_v4l2_object_get_caps as it probes
all the formats. In total, this adds up to about 5 seconds of
execution time, or a 10 second delay while starting up cheese.

These ioctls come from a workaround from 2011 where TRY_FMT might
make changes to hardware settings, so S_FMT was used to restore
the original config:
https://bugzilla.gnome.org/show_bug.cgi?id=649067

The driver bug is now assumed fixed. Remove the workaround to fix the
long startup delay.
Comment 2 Tim-Philipp Müller 2014-06-28 08:53:46 UTC
I have noticed the same on my laptop, takes about 1.5-2.0 seconds to startup v4l2src.
Comment 3 Tim-Philipp Müller 2014-06-28 16:52:04 UTC
This brings startup back down to half a second. I think we should apply this, but then I wasn't happy to have this workaround in our code the first place.

What I find also curious is that I have fast startup with <= 1.2, just master is slow, yet this code is in all branches if I'm not mistaken. (I haven't investigated further though).
Comment 4 Nicolas Dufresne (ndufresne) 2014-06-28 17:15:38 UTC
(In reply to comment #3)
> This brings startup back down to half a second. I think we should apply this,
> but then I wasn't happy to have this workaround in our code the first place.

This workaround caused me serious head-hake when trying to implement M2M support, so I'd be very happy to get rid of it. It will break drivers that simply don't support TRY_FMT (this was added after, so we cannot stand with saying this is a buggy drivers). Would be nice to track when this was added, or what drivers that may still be affected today (for release notes).

> 
> What I find also curious is that I have fast startup with <= 1.2, just master
> is slow, yet this code is in all branches if I'm not mistaken. (I haven't
> investigated further though).

What I think is the caused is that distro kernel are earlier then the distributed headers. This has mean we now do step enumeration when drivers supports it, and we do that enumeration the slowest possible way (by probing every single steps). There is a report for the PyCam and some drivers that expose a step of 1, where things becomes a disaster, and caps become really huge.

See bugs #726521 and #724521

Imho, steps are like range, we should probe the first and the last. We should also have a special case for small steps, to avoid exploding the caps size and let the implicit (through alignment) crop now in place do it's job (for small steps up to 4 pixels, it's really not a problem to crop, we'll need to decide on a threshold).
Comment 5 Daniel Drake 2014-06-30 08:13:25 UTC
Grepping for drivers in the kernel source that mention vidioc_s_fmt but not vidioc_try_fmt, the list is just:

 drivers/media/pci/ttpci/av7110_v4l.c
 drivers/media/platform/s5p-tv/mixer_video.c
 drivers/media/usb/tlg2300/pd-video.c

Note that even after this patch, the v4l2object code still has a fallback on S_FMT if TRY_FMT is not supported, however since it does not do a save/restore of the settings any more, it might mean that the simple act of probing changes the settings of the camera.

What do you think? If you're concerned I could update the patch to only do the save/restore when S_FMT is tried.
Comment 6 Nicolas Dufresne (ndufresne) 2014-06-30 14:18:01 UTC
Right, so the current patch will "break" the fallback as originally designed, as it won't restore the state on fallback. I wonder why is it needed to restore last state in the first place. I'll try and find an answer in old commit messages.

Even if restoring the state is needed, this action should only be done once per probe, not for each format being tested. This would keep old behaviour, and fix the performance issue (well, will still have 0.34 s overhead according to your test, which isn't that low).
Comment 7 Daniel Drake 2014-06-30 16:17:07 UTC
(In reply to comment #6)
> Right, so the current patch will "break" the fallback as originally designed,
> as it won't restore the state on fallback. I wonder why is it needed to restore
> last state in the first place. I'll try and find an answer in old commit
> messages.

Maybe I misunderstood your comment, but didn't I already answer that above?
The save/restore was added to work around a kernel bug in 2011, that bug is closed upstream as obsolete, and I can't reproduce it.

> Even if restoring the state is needed, this action should only be done once per
> probe, not for each format being tested. This would keep old behaviour, and fix
> the performance issue (well, will still have 0.34 s overhead according to your
> test, which isn't that low).

If it sounds OK, tomorrow I will try to write a patch which does:
- save settings at start of probe
- during probe, do TRY_FMT with fallback on S_FMT
- is S_FMT fallback is used, set restore_needed flag
- at end of probe, if restore_needed flag is set, restore the saved settings with another S_FMT
Comment 8 Daniel Drake 2014-07-01 11:18:50 UTC
Sorry if I'm missing something... Is there an obvious reason why adding a boolean field (which I'm not even using yet) to struct _GstV4l2Object (sys/v4l2/gstv4l2object.h) causes:

Setting pipeline to PAUSED ...
Caught SIGSEGV

gdb is not being very helpful...
Comment 9 Daniel Drake 2014-07-01 11:41:16 UTC
Never mind - "make clean" was needed after modifying the header.
Comment 10 Daniel Drake 2014-07-01 12:22:09 UTC
Created attachment 279672 [details] [review]
v4l2object: drop workaround for misbehaving TRY_FMT

This workaround from 2011 was causing 25 S_FMT ioctls to be sent
to my UVC webcam from under gst_v4l2_object_get_caps as it probes
all the formats. In total, this adds up to about 5 seconds of
execution time, or a 10 second delay while starting up cheese.

These ioctls come from a workaround from 2011 where TRY_FMT might
make changes to hardware settings, so S_FMT was used to restore
the original config:
https://bugzilla.gnome.org/show_bug.cgi?id=649067

The driver bug is assumed fixed, so we will drop this slow
workaround for the common case. However, there is still a fallback on
S_FMT for drivers that don't support TRY_FMT, and if we do hit that
codepath, restoring the original format (just once, at end of probe) is
a good idea.
Comment 11 Nicolas Dufresne (ndufresne) 2014-07-01 15:52:51 UTC
What I'm questioning is why do we need this complex save and restore mechanism ? Reading through the bug let me think that the driver issue was that:

- TRY_FMT leads to internal format change
- later G_FMT return an older format
- GStreamer detect no format change and skips S_FMT

This seems more related to the optimization we do to avoid S_FMT when not needed (which might be related to previous attempt doing renegotiation). If driver reports it's internal format wrong, we fail with it. This is very unlike other implementation, which always set the format.

My conclusion is that we should drop the workaround, drop the save and restore (as we will S_FMT if drivers reports a format different from what we want). Then if we face the bug from 2011 again, the proper work around would be to identify that driver string, and for that driver string enable the no_initial_format quirk I have added recently (or simply always set the format and drop the quirk).

Daniel, are you willing to implement this ? I can take care tomorrow otherwise.
Comment 12 Daniel Drake 2014-07-01 16:09:31 UTC
I think I already did - attachment #279374 [details] - drops the workaround, save and restore.

The only problem with that is that for drivers that don't support TRY_FMT, we fall back to S_FMT during probing, which means that probing will change camera settings (which I thought you were opposed to in comment 6).
Comment 13 Nicolas Dufresne (ndufresne) 2014-07-01 16:15:29 UTC
(In reply to comment #12)
> I think I already did - attachment #279374 [details] - drops the workaround, save and
> restore.
> 
> The only problem with that is that for drivers that don't support TRY_FMT, we
> fall back to S_FMT during probing, which means that probing will change camera
> settings (which I thought you were opposed to in comment 6).

The fallback do S_FMT, unless another driver bug, G_FMT will read that last set format, hence v4l2_object_set_format() will behave accordingly to the current format. The entire restore/save mechanism should be dropped, it only made sense for buggy TRY_FMT/G_FMT.
Comment 14 Daniel Drake 2014-07-01 16:21:31 UTC
I think attachment #279374 [details] already drops the whole save/restore mechanism, but I'll be happy to remove more stuff if you point me towards it.

I tested that patch plus a change to the code to temporarily break TRY_FMT so it fell back to S_FMT. Nothing went majorly wrong but the webcam video feed did come up at a lower resolution than normal. (testing with gst-launch v4l2src ! xvimagesink)
Comment 15 Nicolas Dufresne (ndufresne) 2014-07-01 16:33:59 UTC
(In reply to comment #14)
> I think attachment #279374 [details] already drops the whole save/restore mechanism, but
> I'll be happy to remove more stuff if you point me towards it.
> 
> I tested that patch plus a change to the code to temporarily break TRY_FMT so
> it fell back to S_FMT. Nothing went majorly wrong but the webcam video feed did
> come up at a lower resolution than normal. (testing with gst-launch v4l2src !
> xvimagesink)

Sorry, was looking at the latest patch and forgot about the old one. Yes, this one drops the save/restore entirely. and is the way forward. Sorry for the delay, I'm on vacation, so only look at emails ever few days. I also had to figure-out what was all this needed for.
Comment 16 Nicolas Dufresne (ndufresne) 2014-07-01 16:59:35 UTC
Comment on attachment 279374 [details] [review]
v4l2object: drop workaround for misbehaving TRY_FMT

commit f9eb4dd2063c0fd843a2ee08ba23f9535bc636ed
Author: Daniel Drake <drake@endlessm.com>
Date:   Fri Jun 27 11:33:06 2014 +0100

    v4l2object: drop workaround for misbehaving TRY_FMT
    
    This workaround from 2011 was causing 25 S_FMT ioctls to be sent
    to my UVC webcam from under gst_v4l2_object_get_caps as it probes
    all the formats. In total, this adds up to about 5 seconds of
    execution time, or a 10 second delay while starting up cheese.
    
    These ioctls come from a workaround from 2011 where TRY_FMT might
    make changes to hardware settings, so S_FMT was used to restore
    the original config:
    https://bugzilla.gnome.org/show_bug.cgi?id=649067
    
    The driver bug is now assumed fixed. Remove the workaround to fix the
    long startup delay.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=732326
Comment 17 Nicolas Dufresne (ndufresne) 2014-07-01 17:00:07 UTC
Thanks for your contribution.