GNOME Bugzilla – Bug 782627
Cheese starts slowly
Last modified: 2020-11-12 07:12:28 UTC
Ubuntu 17.04, Cheese 3.24, Logitech USB Webcam C270: Starting cheese, it needs 35s until I see a picture. STRACE shows that cheese is waiting 12s in a futex, and 75% of the time it is doing 3000 ioctls with /dev/video0.
Thanks for your bug report. Can you please try to downgrade the cheese and/or try with older kernel to see if it is caused by some recent cheese changes, or is a bug in kernel?
Just a note that it also affects user-accounts panel of gnome-control-center and Bug 783789 contains various debug info...
*** Bug 783789 has been marked as a duplicate of this bug. ***
I am not able to reproduce the slowdown even with an external webcam, however, it hangs completely with kernel-4.12.0-0.rc6.git3.1.fc27.x86_64 with the following backtrace (kernel-4.11.0-1.fc27.x86_64 works nicely):
+ Trace 237595
Thread 1 (Thread 0x7f55659cfac0 (LWP 5292))
So I suppose this is caused by kernel driver and thus NOTGNOME. Can somebody confirms it?
I'm on f26 and I saw this problem 2 months ago at least (I can't remember when precisely). The current kernel is 4.11.6-301
I'm affected by this problem on Ubuntu Desktop 17.10 with a Logitech 9000 Pro I downgraded cheese from 3.26.0-0ubuntu1 to 3.24.0-0ubuntu1 and the kernel from 4.13 to 4.11 to 4.10 without any difference. IT takes roughly 34s to start with an external webcam and 4s with the internal webcam. Strace shows that during startup cheese spends most of its time repeating this sequence with slight variations each time (fmt.pix differs) 1121 10:16:18.795096 ioctl(20, VIDIOC_ENUM_FRAMESIZES, {index=12, pixel_format=v4l2_fourcc('Y', 'U', 'Y', 'V'), type=V4L2_FRMSIZE_TYPE_DISCRETE, discrete={width=960, height=720}}) = 0 1121 10:16:18.795344 ioctl(20, VIDIOC_ENUM_FRAMEINTERVALS, {index=0, pixel_format=v4l2_fourcc('Y', 'U', 'Y', 'V'), width=960, height=720, type=V4L2_FRMIVAL_TYPE_DISCRETE, discrete=1/15}) = 0 1121 10:16:18.795870 ioctl(20, VIDIOC_ENUM_FRAMEINTERVALS, {index=1, pixel_format=v4l2_fourcc('Y', 'U', 'Y', 'V'), width=960, height=720, type=V4L2_FRMIVAL_TYPE_DISCRETE, discrete=1/10}) = 0 1121 10:16:18.796237 ioctl(20, VIDIOC_ENUM_FRAMEINTERVALS, {index=2, pixel_format=v4l2_fourcc('Y', 'U', 'Y', 'V'), width=960, height=720, type=V4L2_FRMIVAL_TYPE_DISCRETE, discrete=1/5}) = 0 1121 10:16:18.796593 ioctl(20, VIDIOC_ENUM_FRAMEINTERVALS, {index=3, pixel_format=v4l2_fourcc('Y', 'U', 'Y', 'V'), width=960, height=720}) = -1 EINVAL (Invalid argument) 1121 10:16:18.797045 ioctl(20, VIDIOC_CROPCAP, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, bounds={left=0, top=0, width=640, height=480}, defrect={left=0, top=0, width=640, height=480}, pixelaspect=1/1}) = 0 1121 10:16:18.797277 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_ANY, bytesperline=0, sizeimage=0, colorspace=0 /* V4L2_COLORSPACE_??? */} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:18.824205 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SMPTE170M} <unfinished ...> 1091 10:16:18.828646 <... poll resumed> ) = 0 (Timeout) 1091 10:16:18.828905 inotify_add_watch(14, "/home/j-lallement/Vid\303\251os/Webcam", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory) 1091 10:16:18.829180 poll([{fd=4, events=POLLIN}, {fd=14, events=POLLIN}], 2, 3995 <unfinished ...> 1121 10:16:18.852812 <... ioctl resumed> => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:18.853124 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SMPTE240M} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:18.881687 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_REC709} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:18.910255 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_470_SYSTEM_M} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:18.937660 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_470_SYSTEM_BG} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:18.964148 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_JPEG} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:18.992298 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:19.021039 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=0x9 /* V4L2_COLORSPACE_??? */} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:19.048770 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=0xa /* V4L2_COLORSPACE_??? */} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:19.077229 ioctl(20, VIDIOC_TRY_FMT, {type=V4L2_BUF_TYPE_VIDEO_CAPTURE, fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=0xb /* V4L2_COLORSPACE_??? */} => fmt.pix={width=960, height=720, pixelformat=v4l2_fourcc('Y', 'U', 'Y', 'V'), field=V4L2_FIELD_NONE, bytesperline=1920, sizeimage=1382400, colorspace=V4L2_COLORSPACE_SRGB}}) = 0 1121 10:16:19.104479 ioctl(20, VIDIOC_ENUM_FRAMESIZES, {index=13, pixel_format=v4l2_fourcc('Y', 'U', 'Y', 'V'), type=V4L2_FRMSIZE_TYPE_DISCRETE, discrete={width=1280, height=720}}) = 0
With Ubuntu 17.10 on Wayland and Cheese 3.26 the Problem disappeared. Do you use Wayland or Xorg?
I tried both and the result is the same. 34s to start with the external camera plugged in.
With gstreamer in debug mode I think the slowness comes from the enumeration of the capabilities of the camera. The external one supporting more format the enumeration is much slower. There is a similar issue with the account settings panel of gnome shell and it's slower to open with the webcam attached and again it's gstreamer spending time probing the video device.
Created attachment 362800 [details] [review] monitor: Implement GAsyncInitable interface Monitor initialization may block if external camera is conbected, probably due to some kernel bug. It causes freezes for applications, which is not acceptable. Let's implement GAsyncInitable interface, so it can be initialized asynchronously.
*** Bug 788749 has been marked as a duplicate of this bug. ***
Review of attachment 362800 [details] [review]: > Monitor initialization may block if external camera is conbected, connected Looks good apart from the 2 nits. Has anyone tested this, and seen problems with it? It doesn't fix the slowness (thus wouldn't fix this bug), but other parts of the UI should still be responsive. ::: libcheese/cheese-camera-device-monitor.c @@ +319,3 @@ +cheese_camera_device_monitor_init (CheeseCameraDeviceMonitor *monitor) +{ + /* Let GInitable to initialize it. */ s/to//
gstreamer git master (upcoming 1.14) should be faster fwiw, but I would still make this async. The v4l2 gstreamer device monitor can also work async, but I don't know if it does currently.
Created attachment 367618 [details] [review] monitor: Implement GAsyncInitable interface Fixes the two nitpicks...
(In reply to Ondrej Holy from comment #14) > Created attachment 367618 [details] [review] [review] > monitor: Implement GAsyncInitable interface > > Fixes the two nitpicks... If you can answer the question in comment 12 about the behaviour, looks good to me otherwise.
No, as I stated on Bug 783789, my external webcam seems broken, so the patches are untested. Respectively it works nicely with my internal webcam, but not sure it helps to fix the issue...
*** Bug 793527 has been marked as a duplicate of this bug. ***
Thanks to all devs working on this issue. It was mentioned that the root cause is likely a kernel bug. Has anyone reported this to the kernel developers? I think it would be a pity if a detected kernel issue goes unreported.
I am convinced I have seen some report for it, but can't find it right now, but probably the following commit fixes the slowdown in GStreamer: https://github.com/GStreamer/gst-plugins-good/commit/4632f33334e7fe32460ef9dcf0bc4f6a3d11762e But it is also a problem that cheese expects that gst_device_monitor_start is nonblocking and use that call in _init.
on my system cheese not even starts. See bug 791703
Review of attachment 367618 [details] [review]: One typo, but otherwise fine. ::: libcheese/cheese-camera-device-monitor.c @@ +337,3 @@ + +/** + * cheese_camera_device_monitor_async: Should be cheese_camera_device_monitor_new_async.
Created attachment 369172 [details] [review] monitor: Implement GAsyncInitable interface Fixed typo.
Thanks, will you make .92 release? May I bump the cheese version now so we can add a dependency on it in g-c-c?
Created attachment 369173 [details] [review] Bump version to 3.27.92 Bump the version so we can use the new API in gnome-control-center.
*** Bug 791703 has been marked as a duplicate of this bug. ***
bugzilla.gnome.org is being replaced by gitlab.gnome.org. We are closing all old bug reports and feature requests in GNOME Bugzilla which have not seen updates for a long time. If you still use cheese and if you still see this bug / want this feature in a recent and currently supported version, then please feel free to report it at https://gitlab.gnome.org/GNOME/cheese/-/issues/ Thank you for creating this report and we are sorry it could not be implemented (volunteer workforce and time is quite limited).