2008-07-07 10:34:47

by Romano Giannetti

[permalink] [raw]
Subject: Linux 2.6.26-rc9 circular lock with uvcvideo on resume from hibernation


Hi,

first of all I'm really happy that uvcvideo has landed on
mainline :-).

I had this warning resuming from hibernation. Seems that the camera is
still working ok. Config, lsusb and lshw attached.

[ 1132.942345] =======================================================
[ 1132.942433] [ INFO: possible circular locking dependency detected ]
[ 1132.942481] 2.6.26-rc9 #62
[ 1132.942520] -------------------------------------------------------
[ 1132.942569] khubd/2264 is trying to acquire lock:
[ 1132.942614] (videodev_lock){--..}, at: [<f89e4595>] video_unregister_device+0x15/0x60 [videodev]
[ 1132.942810]
[ 1132.942811] but task is already holding lock:
[ 1132.942890] (&uvc_driver.open_mutex){--..}, at: [<f8a35c09>] uvc_disconnect+0x29/0x50 [uvcvideo]
[ 1132.943083]
[ 1132.943084] which lock already depends on the new lock.
[ 1132.943086]
[ 1132.943201]
[ 1132.943202] the existing dependency chain (in reverse order) is:
[ 1132.943285]
[ 1132.943286] -> #1 (&uvc_driver.open_mutex){--..}:
[ 1132.943463] [<c0149cae>] __lock_acquire+0xb9e/0xff0
[ 1132.943777] [<c014a178>] lock_acquire+0x78/0xa0
[ 1132.944087] [<c0301dd9>] mutex_lock_nested+0x89/0x290
[ 1132.944403] [<f8a375fa>] uvc_v4l2_open+0x2a/0xd0 [uvcvideo]
[ 1132.944664] [<f89e7ce8>] video_open+0xd8/0x1f0 [videodev]
[ 1132.944664] [<c0189f73>] chrdev_open+0xd3/0x1e0
[ 1132.944664] [<c0185a28>] __dentry_open+0xe8/0x270
[ 1132.944664] [<c0185bf7>] nameidata_to_filp+0x47/0x60
[ 1132.944664] [<c01923fe>] do_filp_open+0x16e/0x760
[ 1132.944664] [<c01857e9>] do_sys_open+0x49/0xe0
[ 1132.944664] [<c01858e9>] sys_open+0x29/0x40
[ 1132.944664] [<c0103dbd>] sysenter_past_esp+0x6a/0xb1
[ 1132.944664] [<ffffffff>] 0xffffffff
[ 1132.944664]
[ 1132.944664] -> #0 (videodev_lock){--..}:
[ 1132.944664] [<c0149ad8>] __lock_acquire+0x9c8/0xff0
[ 1132.944664] [<c014a178>] lock_acquire+0x78/0xa0
[ 1132.944664] [<c0301dd9>] mutex_lock_nested+0x89/0x290
[ 1132.944664] [<f89e4595>] video_unregister_device+0x15/0x60 [videodev]
[ 1132.944664] [<f8a35b35>] uvc_delete+0x25/0xd0 [uvcvideo]
[ 1132.944664] [<c01f0dad>] kref_put+0x2d/0x70
[ 1132.944664] [<f8a35c1a>] uvc_disconnect+0x3a/0x50 [uvcvideo]
[ 1132.944664] [<f8873d92>] usb_unbind_interface+0x52/0xa0 [usbcore]
[ 1132.944664] [<c0254fb9>] __device_release_driver+0x59/0x90
[ 1132.944664] [<c02550c3>] device_release_driver+0x23/0x40
[ 1132.944664] [<c025444e>] bus_remove_device+0x6e/0x90
[ 1132.944664] [<c0252f11>] device_del+0xe1/0x150
[ 1132.944664] [<f8871039>] usb_disable_device+0x79/0xf0 [usbcore]
[ 1132.944664] [<f886c748>] usb_disconnect+0x88/0x120 [usbcore]
[ 1132.944664] [<f886db57>] hub_thread+0x4a7/0xd40 [usbcore]
[ 1132.944664] [<c013a612>] kthread+0x42/0x70
[ 1132.944664] [<c0104a77>] kernel_thread_helper+0x7/0x10
[ 1132.944664] [<ffffffff>] 0xffffffff
[ 1132.944664]
[ 1132.944664] other info that might help us debug this:
[ 1132.944664]
[ 1132.944664] 1 lock held by khubd/2264:
[ 1132.944664] #0: (&uvc_driver.open_mutex){--..}, at: [<f8a35c09>] uvc_disconnect+0x29/0x50 [uvcvideo]
[ 1132.944664]
[ 1132.944664] stack backtrace:
[ 1132.944664] Pid: 2264, comm: khubd Not tainted 2.6.26-rc9 #62
[ 1132.944664] [<c0147d1f>] print_circular_bug_tail+0x6f/0x80
[ 1132.944664] [<c0149ad8>] __lock_acquire+0x9c8/0xff0
[ 1132.944664] [<c014a178>] lock_acquire+0x78/0xa0
[ 1132.944664] [<f89e4595>] ? video_unregister_device+0x15/0x60 [videodev]
[ 1132.944664] [<c0301dd9>] mutex_lock_nested+0x89/0x290
[ 1132.944664] [<f89e4595>] ? video_unregister_device+0x15/0x60 [videodev]
[ 1132.944664] [<c0148ab0>] ? mark_held_locks+0x40/0x80
[ 1132.944664] [<f89e4595>] ? video_unregister_device+0x15/0x60 [videodev]
[ 1132.944664] [<f8a35b10>] ? uvc_delete+0x0/0xd0 [uvcvideo]
[ 1132.944664] [<f89e4595>] video_unregister_device+0x15/0x60 [videodev]
[ 1132.944664] [<f8a35b35>] uvc_delete+0x25/0xd0 [uvcvideo]
[ 1132.944664] [<f8a35b10>] ? uvc_delete+0x0/0xd0 [uvcvideo]
[ 1132.944664] [<c01f0dad>] kref_put+0x2d/0x70
[ 1132.944664] [<f8a35c1a>] uvc_disconnect+0x3a/0x50 [uvcvideo]
[ 1132.944664] [<f8873d92>] usb_unbind_interface+0x52/0xa0 [usbcore]
[ 1132.944664] [<c0254fb9>] __device_release_driver+0x59/0x90
[ 1132.944664] [<c02550c3>] device_release_driver+0x23/0x40
[ 1132.944664] [<c025444e>] bus_remove_device+0x6e/0x90
[ 1132.944664] [<c0252f11>] device_del+0xe1/0x150
[ 1132.944664] [<f8871039>] usb_disable_device+0x79/0xf0 [usbcore]
[ 1132.944664] [<f886c748>] usb_disconnect+0x88/0x120 [usbcore]
[ 1132.944664] [<f886db57>] hub_thread+0x4a7/0xd40 [usbcore]
[ 1132.944664] [<c011ff06>] ? hrtick_set+0x86/0x100
[ 1132.944664] [<c013a900>] ? autoremove_wake_function+0x0/0x40
[ 1132.944664] [<f886d6b0>] ? hub_thread+0x0/0xd40 [usbcore]
[ 1132.944664] [<c013a612>] kthread+0x42/0x70
[ 1132.944664] [<c013a5d0>] ? kthread+0x0/0x70
[ 1132.944664] [<c0104a77>] kernel_thread_helper+0x7/0x10
[ 1132.944664] =======================

--

Romano Giannetti Dep. de Electr?nica y Autom?tica
http://www.dea.icai.upcomillas.es/romano Univ. Pontificia Comillas (MADRID)


--
La presente comunicaci?n tiene car?cter confidencial y es para el exclusivo uso del destinatario indicado en la misma. Si Ud. no es el destinatario indicado, le informamos que cualquier forma de distribuci?n, reproducci?n o uso de esta comunicaci?n y/o de la informaci?n contenida en la misma est?n estrictamente prohibidos por la ley. Si Ud. ha recibido esta comunicaci?n por error, por favor, notif?quelo inmediatamente al remitente contestando a este mensaje y proceda a continuaci?n a destruirlo. Gracias por su colaboraci?n.

This communication contains confidential information. It is for the exclusive use of the intended addressee. If you are not the intended addressee, please note that any form of distribution, copying or use of this communication or the information in it is strictly prohibited by law. If you have received this communication in error, please immediately notify the sender by reply e-mail and destroy this message. Thank you for your cooperation.


Attachments:
config.txt (67.70 kB)
lsusb.txt (238.00 B)
lshw.txt (18.10 kB)
Download all attachments

2008-07-07 17:40:40

by Roland Dreier

[permalink] [raw]
Subject: Re: Linux 2.6.26-rc9 circular lock with uvcvideo on resume from hibernation

> [ 1132.942569] khubd/2264 is trying to acquire lock:
> [ 1132.942614] (videodev_lock){--..}, at: [<f89e4595>] video_unregister_device+0x15/0x60 [videodev]
> [ 1132.942810]
> [ 1132.942811] but task is already holding lock:
> [ 1132.942890] (&uvc_driver.open_mutex){--..}, at: [<f8a35c09>] uvc_disconnect+0x29/0x50 [uvcvideo]

Thanks very much for the report (and for testing development kernels
with lockdep enabled!). I think the patch below should fix this.

Laurent -- if this patch looks good to you, please forward on for
merging.

Thanks,
Roland

---

[PATCH] uvc: Fix possible AB-BA deadlock with videodev_lock and open_mutex

The uvcvideo driver's uvc_v4l2_open() method is called from videodev's
video_open() function, which means it is called with the videodev_lock
mutex held. uvc_v4l2_open() then takes uvc_driver.open_mutex to check
dev->state and avoid racing against a device disconnect, which means
that open_mutex must nest inside videodev_lock.

However uvc_disconnect() takes the open_mutex around setting
dev->state and also around putting its device reference. However, if
uvc_disconnect() ends up dropping the last reference, it will call
uvc_delete(), which calls into the videodev code to unregister its
device, and this will end up taking videodev_lock. This opens a
(unlikely in practice) window for an AB-BA deadlock and also causes a
lockdep warning because of the lock misordering.

Fortunately there is no apparent reason to hold open_mutex when doing
kref_put() in uvc_disconnect(): if uvc_v4l2_open() runs before the
state is set to UVC_DEV_DISCONNECTED, then it will take another
reference to the device and kref_put() won't call uvc_delete; if
uvc_v4l2_open() runs after the state is set, it will run before
uvc_delete(), see the state, and return immediately -- uvc_delete()
does uvc_unregister_video() (and hence video_unregister_device(),
which is synchronized with videodev_lock) as its first thing, so there
is no risk of use-after-free in uvc_v4l2_open().

Bug diagnosed based on a lockdep warning reported by Romano Giannetti
<[email protected]>.

Signed-off-by: Roland Dreier <[email protected]>
---
drivers/media/video/uvc/uvc_driver.c | 5 ++---
1 files changed, 2 insertions(+), 3 deletions(-)

diff --git a/drivers/media/video/uvc/uvc_driver.c b/drivers/media/video/uvc/uvc_driver.c
index 60ced58..5d60cb3 100644
--- a/drivers/media/video/uvc/uvc_driver.c
+++ b/drivers/media/video/uvc/uvc_driver.c
@@ -1634,11 +1634,10 @@ static void uvc_disconnect(struct usb_interface *intf)
* chance to increase the reference count (kref_get).
*/
mutex_lock(&uvc_driver.open_mutex);
-
dev->state |= UVC_DEV_DISCONNECTED;
- kref_put(&dev->kref, uvc_delete);
-
mutex_unlock(&uvc_driver.open_mutex);
+
+ kref_put(&dev->kref, uvc_delete);
}

static int uvc_suspend(struct usb_interface *intf, pm_message_t message)

2008-07-09 19:29:19

by Laurent Pinchart

[permalink] [raw]
Subject: Re: Linux 2.6.26-rc9 circular lock with uvcvideo on resume from hibernation

Hi Romano and Roland,

On Monday 07 July 2008, Roland Dreier wrote:
> > [ 1132.942569] khubd/2264 is trying to acquire lock:
> > [ 1132.942614] (videodev_lock){--..}, at: [<f89e4595>]
> > video_unregister_device+0x15/0x60 [videodev] [ 1132.942810]
> > [ 1132.942811] but task is already holding lock:
> > [ 1132.942890] (&uvc_driver.open_mutex){--..}, at: [<f8a35c09>]
> > uvc_disconnect+0x29/0x50 [uvcvideo]
>
> Thanks very much for the report (and for testing development kernels
> with lockdep enabled!).

I second this. Thanks a lot.

> I think the patch below should fix this.
>
> Laurent -- if this patch looks good to you, please forward on for
> merging.
>
> Thanks,
> Roland
>
> ---
>
> [PATCH] uvc: Fix possible AB-BA deadlock with videodev_lock and open_mutex
>
> The uvcvideo driver's uvc_v4l2_open() method is called from videodev's
> video_open() function, which means it is called with the videodev_lock
> mutex held. uvc_v4l2_open() then takes uvc_driver.open_mutex to check
> dev->state and avoid racing against a device disconnect, which means
> that open_mutex must nest inside videodev_lock.

The open_mutex lock's main purpose is to prevent uvc_delete() being called
from kref_put() while an open operation is in progress. Protected dev->state
is a side effect which might not be required.

> However uvc_disconnect() takes the open_mutex around setting
> dev->state and also around putting its device reference. However, if
> uvc_disconnect() ends up dropping the last reference, it will call
> uvc_delete(), which calls into the videodev code to unregister its
> device, and this will end up taking videodev_lock. This opens a
> (unlikely in practice) window for an AB-BA deadlock and also causes a
> lockdep warning because of the lock misordering.

I agree with this analysis.

> Fortunately there is no apparent reason to hold open_mutex when doing
> kref_put() in uvc_disconnect(): if uvc_v4l2_open() runs before the
> state is set to UVC_DEV_DISCONNECTED, then it will take another
> reference to the device and kref_put() won't call uvc_delete; if
> uvc_v4l2_open() runs after the state is set, it will run before
> uvc_delete(), see the state, and return immediately -- uvc_delete()
> does uvc_unregister_video() (and hence video_unregister_device(),
> which is synchronized with videodev_lock) as its first thing, so there
> is no risk of use-after-free in uvc_v4l2_open().

This introduces a race condition, see below.

> Bug diagnosed based on a lockdep warning reported by Romano Giannetti
> <[email protected]>.
>
> Signed-off-by: Roland Dreier <[email protected]>
> ---
> drivers/media/video/uvc/uvc_driver.c | 5 ++---
> 1 files changed, 2 insertions(+), 3 deletions(-)
>
> diff --git a/drivers/media/video/uvc/uvc_driver.c
> b/drivers/media/video/uvc/uvc_driver.c index 60ced58..5d60cb3 100644
> --- a/drivers/media/video/uvc/uvc_driver.c
> +++ b/drivers/media/video/uvc/uvc_driver.c
> @@ -1634,11 +1634,10 @@ static void uvc_disconnect(struct usb_interface
> *intf) * chance to increase the reference count (kref_get).
> */
> mutex_lock(&uvc_driver.open_mutex);
> -
> dev->state |= UVC_DEV_DISCONNECTED;
> - kref_put(&dev->kref, uvc_delete);
> -
> mutex_unlock(&uvc_driver.open_mutex);
> +
> + kref_put(&dev->kref, uvc_delete);
> }
>
> static int uvc_suspend(struct usb_interface *intf, pm_message_t message)

uvc_disconnect() | uvc_v4l2_open()
... |
mutex_lock(&uvc_driver.open_mutex); |
dev->state |= UVC_DEV_DISCONNECTED; |
mutex_unlock(&uvc_driver.open_mutex); |
|
| mutex_lock(&uvc_driver.open_mutex);
| vdev = video_devdata(file);
| video = video_get_drvdata(vdev);
|
kref_put(&dev->kref, uvc_delete); |
|
| if (video->dev->state...)

kref_put() in uvc_disconnect() will call uvc_delete(), which will in turn free
the video structure. uvc_v4l2_open() will then dereference freed memory when
testing the device state.

I proper fix will involve videodev modifications. Fortunately, David
Ellingsworth posted a videodev patch to address the same kind of issue a few
days ago. Search the video4linux mailing list for a thread called "[PATCH]
videodev: fix sysfs kobj ref count". I'm currently reviewing his patch. As
soon as a proper fix is applied to videodev I will probably drop the
open_mutex lock acquisition in uvc_disconnect().

In the meantime, and for kernel versions that don't include the videodev
patch, I don't know what to choose between a race condition that can lead to
freed memory dereference, and a AB-BA deadlock. Any opinion on that ?

Best regards,

Laurent Pinchart

2008-07-09 19:53:46

by Roland Dreier

[permalink] [raw]
Subject: Re: Linux 2.6.26-rc9 circular lock with uvcvideo on resume from hibernation

> uvc_disconnect() | uvc_v4l2_open()
> ... |
> mutex_lock(&uvc_driver.open_mutex); |
> dev->state |= UVC_DEV_DISCONNECTED; |
> mutex_unlock(&uvc_driver.open_mutex); |
> |
> | mutex_lock(&uvc_driver.open_mutex);
> | vdev = video_devdata(file);
> | video = video_get_drvdata(vdev);
> |
> kref_put(&dev->kref, uvc_delete); |
> |
> | if (video->dev->state...)
>
> kref_put() in uvc_disconnect() will call uvc_delete(), which will in turn free
> the video structure. uvc_v4l2_open() will then dereference freed memory when
> testing the device state.

I don't believe this is correct. I tried to explain it in my
changelog by saying "uvc_delete() does uvc_unregister_video() (and
hence video_unregister_device(), which is synchronized with
videodev_lock) as its first thing, so there is no risk of
use-after-free in uvc_v4l2_open()."

In other words, the first thing uvc_delete() does is call
uvc_unregister_video(), which will video_unregister_device(). Since
this needs to take videodev_lock, it will wait until uvc_v4l2_open()
returns (which it will do, since state is now UVC_DEV_DISCONNECTED).
So the video struct will not be freed until after uvc_v4l2_open()
returns.

As far as I can see there is no use-after-free.

- R.
--
Roland Dreier <[email protected]> GPG Key: 1024D/E0EEFAC0
Fingerprint: A89F B5E9 C185 F34D BD50 4009 37E2 25CC E0EE FAC0

Sending >500KB attachments is forbidden by the Geneva Convention.
Your country may be at risk if you fail to comply.

2008-07-09 20:11:04

by Laurent Pinchart

[permalink] [raw]
Subject: Re: Linux 2.6.26-rc9 circular lock with uvcvideo on resume from hibernation

On Wednesday 09 July 2008, Roland Dreier wrote:
> > uvc_disconnect() | uvc_v4l2_open()
> > ... |
> > mutex_lock(&uvc_driver.open_mutex); |
> > dev->state |= UVC_DEV_DISCONNECTED; |
> > mutex_unlock(&uvc_driver.open_mutex); |
> >
> > | mutex_lock(&uvc_driver.open_mute
> > |x); vdev = video_devdata(file);
> > | video = video_get_drvdata(vdev);
> >
> > kref_put(&dev->kref, uvc_delete); |
> >
> > | if (video->dev->state...)
> >
> > kref_put() in uvc_disconnect() will call uvc_delete(), which will in
> > turn free the video structure. uvc_v4l2_open() will then dereference
> > freed memory when testing the device state.
>
> I don't believe this is correct. I tried to explain it in my
> changelog by saying "uvc_delete() does uvc_unregister_video() (and
> hence video_unregister_device(), which is synchronized with
> videodev_lock) as its first thing, so there is no risk of
> use-after-free in uvc_v4l2_open()."
>
> In other words, the first thing uvc_delete() does is call
> uvc_unregister_video(), which will video_unregister_device(). Since
> this needs to take videodev_lock, it will wait until uvc_v4l2_open()
> returns (which it will do, since state is now UVC_DEV_DISCONNECTED).
> So the video struct will not be freed until after uvc_v4l2_open()
> returns.
>
> As far as I can see there is no use-after-free.

My bad, you seem to be right. I'll apply your patch.

Have you checked David's videodev patch ? Any opinion ?

Best regards,

Laurent Pinchart

2008-07-09 20:17:41

by Roland Dreier

[permalink] [raw]
Subject: Re: Linux 2.6.26-rc9 circular lock with uvcvideo on resume from hibernation

> Have you checked David's videodev patch ? Any opinion ?

Not yet... I'll search for it.
--

Roland Dreier <[email protected]> GPG Key: 1024D/E0EEFAC0
Fingerprint: A89F B5E9 C185 F34D BD50 4009 37E2 25CC E0EE FAC0

Sending >500KB attachments is forbidden by the Geneva Convention.
Your country may be at risk if you fail to comply.