Re: [ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
Hi Sanser,
On Sunday 06 May 2012 16:54:40 Sander Eikelenboom wrote:
Hello Laurent / Mauro,
I have updated to latest 3.4-rc5-tip, running multiple video grabbers.
I don't see anything specific to uvcvideo anymore, but i do get the possible
circular locking dependency below.
Thanks for the report.
We indeed have a serious issue there (CC'ing Hans Verkuil).
Hans, serializing both ioctl handling an mmap with a single device lock as we
currently do in V4L2 is prone to AB-BA deadlocks (uvcvideo shouldn't be
affected as it has no device-wide lock).
If we want to keep a device-wide lock we need to take it after the mm-
mmap_sem lock in all code paths, as there's no way we can change the lock
ordering for mmap(). The copy_from_user/copy_to_user issue could be solved by
moving locking from v4l2_ioctl to __video_do_ioctl (device-wide locks would
then require using video_ioctl2), but I'm not sure whether that will play
nicely with the QBUF implementation in videobuf2 (which already includes a
workaround for this particular AB-BA deadlock issue).
[ 96.257129] ==
[ 96.257129] [ INFO: possible circular locking dependency detected ]
[ 96.257129] 3.4.0-rc5-20120506+ #4 Not tainted
[ 96.257129] ---
[ 96.257129] motion/2289 is trying to acquire lock:
[ 96.257129] (dev-lock){+.+.+.}, at: [8156c04c]
v4l2_mmap+0xbc/0xd0
[ 96.257129]
[ 96.257129] but task is already holding lock:
[ 96.257129] (mm-mmap_sem){++}, at: [81113cca]
sys_mmap_pgoff+0x1ca/0x220
[ 96.257129]
[ 96.257129] which lock already depends on the new lock.
[ 96.257129]
[ 96.257129]
[ 96.257129] the existing dependency chain (in reverse order) is:
[ 96.257129]
[ 96.257129] - #1 (mm-mmap_sem){++}:
[ 96.257129][810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129][810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129][81108cb8] might_fault+0x68/0x90
[ 96.257129][8156d2a1] video_usercopy+0x1d1/0x4e0
[ 96.257129][8156d5c0] video_ioctl2+0x10/0x20
[ 96.257129][8156c110] v4l2_ioctl+0xb0/0x180
[ 96.257129][8114dc3c] do_vfs_ioctl+0x9c/0x580
[ 96.257129][8114e16a] sys_ioctl+0x4a/0x80
[ 96.257129][81813039] system_call_fastpath+0x16/0x1b
[ 96.257129]
[ 96.257129] - #0 (dev-lock){+.+.+.}:
[ 96.257129][810aa529] validate_chain+0x1259/0x1300
[ 96.257129][810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129][810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129][8180e58c]
mutex_lock_interruptible_nested+0x5c/0x550
[ 96.257129][8156c04c] v4l2_mmap+0xbc/0xd0
[ 96.257129][8111359a] mmap_region+0x3da/0x5a0
[ 96.257129][81113ab4] do_mmap_pgoff+0x354/0x3a0
[ 96.257129][81113ce9] sys_mmap_pgoff+0x1e9/0x220
[ 96.257129][81011ee9] sys_mmap+0x29/0x30
[ 96.257129][81813039] system_call_fastpath+0x16/0x1b
[ 96.257129]
[ 96.257129] other info that might help us debug this:
[ 96.257129]
[ 96.257129] Possible unsafe locking scenario:
[ 96.257129]
[ 96.257129]CPU0CPU1
[ 96.257129]
[ 96.257129] lock(mm-mmap_sem);
[ 96.257129]lock(dev-lock);
[ 96.257129]lock(mm-mmap_sem);
[ 96.257129] lock(dev-lock);
[ 96.257129]
[ 96.257129] *** DEADLOCK ***
[ 96.257129]
[ 96.257129] 1 lock held by motion/2289:
[ 96.257129] #0: (mm-mmap_sem){++}, at: [81113cca]
sys_mmap_pgoff+0x1ca/0x220
[ 96.257129]
[ 96.257129] stack backtrace:
[ 96.257129] Pid: 2289, comm: motion Not tainted 3.4.0-rc5-20120506+ #4
[ 96.257129] Call Trace:
[ 96.257129] [810a8fb6] print_circular_bug+0x206/0x300
[ 96.257129] [810aa529] validate_chain+0x1259/0x1300
[ 96.257129] [810a9417] ? validate_chain+0x147/0x1300
[ 96.257129] [810ab773] ? lock_release+0x113/0x260
[ 96.257129] [810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129] [810aa993] ? __lock_acquire+0x3c3/0xc50
[ 96.257129] [8156024c] ? tda18271_tune+0x71c/0x9c0
[ 96.257129] [810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129] [8156c04c] ? v4l2_mmap+0xbc/0xd0
[ 96.257129] [8180e58c]
mutex_lock_interruptible_nested+0x5c/0x550
[ 96.257129] [8156c04c] ? v4l2_mmap+0xbc/0xd0
[ 96.257129] [810a77ce] ? mark_held_locks+0x9e/0x130
[ 96.257129] [8156c04c] ? v4l2_mmap+0xbc/0xd0
[ 96.257129] [811134de] ? mmap_region+0x31e/0x5a0
[ 96.257129] [810a7900] ? lockdep_trace_alloc+0xa0/0x130
[
Re: [ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
On Monday 07 May 2012 13:06:01 Laurent Pinchart wrote:
Hi Sanser,
On Sunday 06 May 2012 16:54:40 Sander Eikelenboom wrote:
Hello Laurent / Mauro,
I have updated to latest 3.4-rc5-tip, running multiple video grabbers.
I don't see anything specific to uvcvideo anymore, but i do get the possible
circular locking dependency below.
Thanks for the report.
We indeed have a serious issue there (CC'ing Hans Verkuil).
Hans, serializing both ioctl handling an mmap with a single device lock as we
currently do in V4L2 is prone to AB-BA deadlocks (uvcvideo shouldn't be
affected as it has no device-wide lock).
If we want to keep a device-wide lock we need to take it after the mm-
mmap_sem lock in all code paths, as there's no way we can change the lock
ordering for mmap(). The copy_from_user/copy_to_user issue could be solved by
moving locking from v4l2_ioctl to __video_do_ioctl (device-wide locks would
then require using video_ioctl2), but I'm not sure whether that will play
nicely with the QBUF implementation in videobuf2 (which already includes a
workaround for this particular AB-BA deadlock issue).
I've seen the same thing. It was on my TODO list of things to look into. I think
mmap shouldn't take the device wide lock at all. But it will mean reviewing
affected drivers before I can remove it.
To be honest, I wasn't sure whether or not to take the device lock for mmap when
I first wrote that code.
If you look at irc I had a discussion today with HdG about adding flags to
selectively disable locks for fops. It may be an idea to implement this soon so
we can start updating drivers one-by-one.
Frankly, I do not believe this 'possible circular locking' thing to be a real
bug as I am not aware of drivers that use the device lock *and* lock mmap_sem.
If I understand Sander correctly 'motion' no longer locks up after moving to
3.4-rc5-tip, right?
I have to look into a bit more to see what the best approach it so we can
prevent
this message from appearing.
Regards,
Hans
[ 96.257129] ==
[ 96.257129] [ INFO: possible circular locking dependency detected ]
[ 96.257129] 3.4.0-rc5-20120506+ #4 Not tainted
[ 96.257129] ---
[ 96.257129] motion/2289 is trying to acquire lock:
[ 96.257129] (dev-lock){+.+.+.}, at: [8156c04c]
v4l2_mmap+0xbc/0xd0
[ 96.257129]
[ 96.257129] but task is already holding lock:
[ 96.257129] (mm-mmap_sem){++}, at: [81113cca]
sys_mmap_pgoff+0x1ca/0x220
[ 96.257129]
[ 96.257129] which lock already depends on the new lock.
[ 96.257129]
[ 96.257129]
[ 96.257129] the existing dependency chain (in reverse order) is:
[ 96.257129]
[ 96.257129] - #1 (mm-mmap_sem){++}:
[ 96.257129][810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129][810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129][81108cb8] might_fault+0x68/0x90
[ 96.257129][8156d2a1] video_usercopy+0x1d1/0x4e0
[ 96.257129][8156d5c0] video_ioctl2+0x10/0x20
[ 96.257129][8156c110] v4l2_ioctl+0xb0/0x180
[ 96.257129][8114dc3c] do_vfs_ioctl+0x9c/0x580
[ 96.257129][8114e16a] sys_ioctl+0x4a/0x80
[ 96.257129][81813039] system_call_fastpath+0x16/0x1b
[ 96.257129]
[ 96.257129] - #0 (dev-lock){+.+.+.}:
[ 96.257129][810aa529] validate_chain+0x1259/0x1300
[ 96.257129][810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129][810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129][8180e58c]
mutex_lock_interruptible_nested+0x5c/0x550
[ 96.257129][8156c04c] v4l2_mmap+0xbc/0xd0
[ 96.257129][8111359a] mmap_region+0x3da/0x5a0
[ 96.257129][81113ab4] do_mmap_pgoff+0x354/0x3a0
[ 96.257129][81113ce9] sys_mmap_pgoff+0x1e9/0x220
[ 96.257129][81011ee9] sys_mmap+0x29/0x30
[ 96.257129][81813039] system_call_fastpath+0x16/0x1b
[ 96.257129]
[ 96.257129] other info that might help us debug this:
[ 96.257129]
[ 96.257129] Possible unsafe locking scenario:
[ 96.257129]
[ 96.257129]CPU0CPU1
[ 96.257129]
[ 96.257129] lock(mm-mmap_sem);
[ 96.257129]lock(dev-lock);
[ 96.257129]lock(mm-mmap_sem);
[ 96.257129] lock(dev-lock);
[ 96.257129]
[ 96.257129] *** DEADLOCK ***
[ 96.257129]
[ 96.257129] 1 lock held by motion/2289:
[ 96.257129] #0: (mm-mmap_sem){++}, at: [81113cca]
sys_mmap_pgoff+0x1ca/0x220
[ 96.257129]
[ 96.257129] stack backtrace:
[ 96.257129] Pid: 2289, comm:
Re: [ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
Hi Hans, On Monday 07 May 2012 13:44:59 Hans Verkuil wrote: On Monday 07 May 2012 13:06:01 Laurent Pinchart wrote: On Sunday 06 May 2012 16:54:40 Sander Eikelenboom wrote: Hello Laurent / Mauro, I have updated to latest 3.4-rc5-tip, running multiple video grabbers. I don't see anything specific to uvcvideo anymore, but i do get the possible circular locking dependency below. Thanks for the report. We indeed have a serious issue there (CC'ing Hans Verkuil). Hans, serializing both ioctl handling an mmap with a single device lock as we currently do in V4L2 is prone to AB-BA deadlocks (uvcvideo shouldn't be affected as it has no device-wide lock). If we want to keep a device-wide lock we need to take it after the mm- mmap_sem lock in all code paths, as there's no way we can change the lock ordering for mmap(). The copy_from_user/copy_to_user issue could be solved by moving locking from v4l2_ioctl to __video_do_ioctl (device-wide locks would then require using video_ioctl2), but I'm not sure whether that will play nicely with the QBUF implementation in videobuf2 (which already includes a workaround for this particular AB-BA deadlock issue). I've seen the same thing. It was on my TODO list of things to look into. I think mmap shouldn't take the device wide lock at all. But it will mean reviewing affected drivers before I can remove it. To be honest, I wasn't sure whether or not to take the device lock for mmap when I first wrote that code. If you look at irc I had a discussion today with HdG about adding flags to selectively disable locks for fops. It may be an idea to implement this soon so we can start updating drivers one-by-one. Frankly, I do not believe this 'possible circular locking' thing to be a real bug as I am not aware of drivers that use the device lock *and* lock mmap_sem. If I understand Sander correctly 'motion' no longer locks up after moving to 3.4-rc5-tip, right? copy_from_user()/copy_to_user() perform a down_read(mm-mmap_sem) when a page fault occurs. All drivers thus potentially take mm-mmap_sem when an ioctl is performed. I have to look into a bit more to see what the best approach it so we can prevent this message from appearing. -- Regards, Laurent Pinchart -- To unsubscribe from this list: send the line unsubscribe linux-media in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
On Monday 07 May 2012 13:47:45 Laurent Pinchart wrote: Hi Hans, On Monday 07 May 2012 13:44:59 Hans Verkuil wrote: On Monday 07 May 2012 13:06:01 Laurent Pinchart wrote: On Sunday 06 May 2012 16:54:40 Sander Eikelenboom wrote: Hello Laurent / Mauro, I have updated to latest 3.4-rc5-tip, running multiple video grabbers. I don't see anything specific to uvcvideo anymore, but i do get the possible circular locking dependency below. Thanks for the report. We indeed have a serious issue there (CC'ing Hans Verkuil). Hans, serializing both ioctl handling an mmap with a single device lock as we currently do in V4L2 is prone to AB-BA deadlocks (uvcvideo shouldn't be affected as it has no device-wide lock). If we want to keep a device-wide lock we need to take it after the mm- mmap_sem lock in all code paths, as there's no way we can change the lock ordering for mmap(). The copy_from_user/copy_to_user issue could be solved by moving locking from v4l2_ioctl to __video_do_ioctl (device-wide locks would then require using video_ioctl2), but I'm not sure whether that will play nicely with the QBUF implementation in videobuf2 (which already includes a workaround for this particular AB-BA deadlock issue). I've seen the same thing. It was on my TODO list of things to look into. I think mmap shouldn't take the device wide lock at all. But it will mean reviewing affected drivers before I can remove it. To be honest, I wasn't sure whether or not to take the device lock for mmap when I first wrote that code. If you look at irc I had a discussion today with HdG about adding flags to selectively disable locks for fops. It may be an idea to implement this soon so we can start updating drivers one-by-one. Frankly, I do not believe this 'possible circular locking' thing to be a real bug as I am not aware of drivers that use the device lock *and* lock mmap_sem. If I understand Sander correctly 'motion' no longer locks up after moving to 3.4-rc5-tip, right? copy_from_user()/copy_to_user() perform a down_read(mm-mmap_sem) when a page fault occurs. All drivers thus potentially take mm-mmap_sem when an ioctl is performed. Ah, I didn't know that. Interesting. Regards, Hans I have to look into a bit more to see what the best approach it so we can prevent this message from appearing. -- To unsubscribe from this list: send the line unsubscribe linux-media in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
Hi, On 05/07/2012 01:44 PM, Hans Verkuil wrote: On Monday 07 May 2012 13:06:01 Laurent Pinchart wrote: Hi Sanser, On Sunday 06 May 2012 16:54:40 Sander Eikelenboom wrote: Hello Laurent / Mauro, I have updated to latest 3.4-rc5-tip, running multiple video grabbers. I don't see anything specific to uvcvideo anymore, but i do get the possible circular locking dependency below. Thanks for the report. We indeed have a serious issue there (CC'ing Hans Verkuil). Hans, serializing both ioctl handling an mmap with a single device lock as we currently do in V4L2 is prone to AB-BA deadlocks (uvcvideo shouldn't be affected as it has no device-wide lock). If we want to keep a device-wide lock we need to take it after the mm- mmap_sem lock in all code paths, as there's no way we can change the lock ordering for mmap(). The copy_from_user/copy_to_user issue could be solved by moving locking from v4l2_ioctl to __video_do_ioctl (device-wide locks would then require using video_ioctl2), but I'm not sure whether that will play nicely with the QBUF implementation in videobuf2 (which already includes a workaround for this particular AB-BA deadlock issue). I've seen the same thing. It was on my TODO list of things to look into. I think mmap shouldn't take the device wide lock at all. But it will mean reviewing affected drivers before I can remove it. To be honest, I wasn't sure whether or not to take the device lock for mmap when I first wrote that code. If you look at irc I had a discussion today with HdG about adding flags to selectively disable locks for fops. It may be an idea to implement this soon so we can start updating drivers one-by-one. I've a patch almost ready for this, when I'm happy with it I'll send of a new version of the (ever growing) gspca use control framework patchset both me and the other Hans have been working on, which will include this patch. Regards, Hans -- To unsubscribe from this list: send the line unsubscribe linux-media in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
Hello Laurent / Mauro,
I have updated to latest 3.4-rc5-tip, running multiple video grabbers.
I don't see anything specific to uvcvideo anymore, but i do get the possible
circular locking dependency below.
--
Sander
[ 96.257129] ==
[ 96.257129] [ INFO: possible circular locking dependency detected ]
[ 96.257129] 3.4.0-rc5-20120506+ #4 Not tainted
[ 96.257129] ---
[ 96.257129] motion/2289 is trying to acquire lock:
[ 96.257129] (dev-lock){+.+.+.}, at: [8156c04c]
v4l2_mmap+0xbc/0xd0
[ 96.257129]
[ 96.257129] but task is already holding lock:
[ 96.257129] (mm-mmap_sem){++}, at: [81113cca]
sys_mmap_pgoff+0x1ca/0x220
[ 96.257129]
[ 96.257129] which lock already depends on the new lock.
[ 96.257129]
[ 96.257129]
[ 96.257129] the existing dependency chain (in reverse order) is:
[ 96.257129]
[ 96.257129] - #1 (mm-mmap_sem){++}:
[ 96.257129][810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129][810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129][81108cb8] might_fault+0x68/0x90
[ 96.257129][8156d2a1] video_usercopy+0x1d1/0x4e0
[ 96.257129][8156d5c0] video_ioctl2+0x10/0x20
[ 96.257129][8156c110] v4l2_ioctl+0xb0/0x180
[ 96.257129][8114dc3c] do_vfs_ioctl+0x9c/0x580
[ 96.257129][8114e16a] sys_ioctl+0x4a/0x80
[ 96.257129][81813039] system_call_fastpath+0x16/0x1b
[ 96.257129]
[ 96.257129] - #0 (dev-lock){+.+.+.}:
[ 96.257129][810aa529] validate_chain+0x1259/0x1300
[ 96.257129][810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129][810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129][8180e58c]
mutex_lock_interruptible_nested+0x5c/0x550
[ 96.257129][8156c04c] v4l2_mmap+0xbc/0xd0
[ 96.257129][8111359a] mmap_region+0x3da/0x5a0
[ 96.257129][81113ab4] do_mmap_pgoff+0x354/0x3a0
[ 96.257129][81113ce9] sys_mmap_pgoff+0x1e9/0x220
[ 96.257129][81011ee9] sys_mmap+0x29/0x30
[ 96.257129][81813039] system_call_fastpath+0x16/0x1b
[ 96.257129]
[ 96.257129] other info that might help us debug this:
[ 96.257129]
[ 96.257129] Possible unsafe locking scenario:
[ 96.257129]
[ 96.257129]CPU0CPU1
[ 96.257129]
[ 96.257129] lock(mm-mmap_sem);
[ 96.257129]lock(dev-lock);
[ 96.257129]lock(mm-mmap_sem);
[ 96.257129] lock(dev-lock);
[ 96.257129]
[ 96.257129] *** DEADLOCK ***
[ 96.257129]
[ 96.257129] 1 lock held by motion/2289:
[ 96.257129] #0: (mm-mmap_sem){++}, at: [81113cca]
sys_mmap_pgoff+0x1ca/0x220
[ 96.257129]
[ 96.257129] stack backtrace:
[ 96.257129] Pid: 2289, comm: motion Not tainted 3.4.0-rc5-20120506+ #4
[ 96.257129] Call Trace:
[ 96.257129] [810a8fb6] print_circular_bug+0x206/0x300
[ 96.257129] [810aa529] validate_chain+0x1259/0x1300
[ 96.257129] [810a9417] ? validate_chain+0x147/0x1300
[ 96.257129] [810ab773] ? lock_release+0x113/0x260
[ 96.257129] [810aa972] __lock_acquire+0x3a2/0xc50
[ 96.257129] [810aa993] ? __lock_acquire+0x3c3/0xc50
[ 96.257129] [8156024c] ? tda18271_tune+0x71c/0x9c0
[ 96.257129] [810ab2e8] lock_acquire+0xc8/0x110
[ 96.257129] [8156c04c] ? v4l2_mmap+0xbc/0xd0
[ 96.257129] [8180e58c] mutex_lock_interruptible_nested+0x5c/0x550
[ 96.257129] [8156c04c] ? v4l2_mmap+0xbc/0xd0
[ 96.257129] [810a77ce] ? mark_held_locks+0x9e/0x130
[ 96.257129] [8156c04c] ? v4l2_mmap+0xbc/0xd0
[ 96.257129] [811134de] ? mmap_region+0x31e/0x5a0
[ 96.257129] [810a7900] ? lockdep_trace_alloc+0xa0/0x130
[ 96.257129] [8156c04c] v4l2_mmap+0xbc/0xd0
[ 96.257129] [8111359a] mmap_region+0x3da/0x5a0
[ 96.257129] [81113ab4] do_mmap_pgoff+0x354/0x3a0
[ 96.257129] [81113ce9] sys_mmap_pgoff+0x1e9/0x220
[ 96.257129] [8132554e] ? trace_hardirqs_on_thunk+0x3a/0x3f
[ 96.257129] [81011ee9] sys_mmap+0x29/0x30
Monday, April 30, 2012, 1:05:27 AM, you wrote:
Hi Sander,
On Saturday 28 April 2012 22:02:46 Sander Eikelenboom wrote:
Hi,
I'm using a webcam (logitech) supported by the uvcvideo module to capture
video. Previously once in a while I would get the uvcvideo: Failed to
resubmit video URB (-27)., but the grabbing continued without a problem.
Now the video grabbing program (motion) seems to lock due to some nested
lock if i interpret it right.
The uvcvideo driver doesn't use nested locks, this is just a normal locking
issue. The
Re: [ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
Hi Sander,
On Saturday 28 April 2012 22:02:46 Sander Eikelenboom wrote:
Hi,
I'm using a webcam (logitech) supported by the uvcvideo module to capture
video. Previously once in a while I would get the uvcvideo: Failed to
resubmit video URB (-27)., but the grabbing continued without a problem.
Now the video grabbing program (motion) seems to lock due to some nested
lock if i interpret it right.
The uvcvideo driver doesn't use nested locks, this is just a normal locking
issue. The mutex_lock_nested() call in the backtrace comes from lock debugging
support in your kernel.
A quick look at the code doesn't reveal any obvious locking issue. Do you have
multiple threads accessing the device at the same time ?
Additional problem is that i don't really know what kernel version was still
OK, so can't help with that info.
This is on a vanilla 3.4 RC kernel latest commit:
c629eaf8392b676b4f83c3dc344e66402bfeec92
[ 3696.753490] ehci_hcd :09:00.1: request 880016091400 would
overflow (3923+31 = 3936) [ 3696.753494] uvcvideo: Failed to resubmit
video URB (-27).
[ 3696.753563] ehci_hcd :09:00.1: request 880016091800 would
overflow (3922+31 = 3936) [ 3696.753566] uvcvideo: Failed to resubmit
video URB (-27).
[ 3696.753609] ehci_hcd :09:00.1: request 880016090800 would
overflow (3922+31 = 3936) [ 3696.753611] uvcvideo: Failed to resubmit
video URB (-27).
[ 3696.753645] ehci_hcd :09:00.1: request 880016090c00 would
overflow (3922+31 = 3936) [ 3696.753647] uvcvideo: Failed to resubmit
video URB (-27).
[ 3696.753656] ehci_hcd :09:00.1: request 880016091000 would
overflow (3922+31 = 3936) [ 3696.753657] uvcvideo: Failed to resubmit
video URB (-27).
[ 3960.758154] INFO: task motion:7776 blocked for more than 120 seconds.
[ 3960.758168] echo 0 /proc/sys/kernel/hung_task_timeout_secs disables
this message. [ 3960.758174] motion D 0201 0 7776
1 0x [ 3960.758183] 8800239d9b68 0216
eaa50018 810a451b [ 3960.758192] 88002392cf60
00012600 8800239d9fd8 8800239d8010 [ 3960.758200]
00012600 00012600 8800239d9fd8 00012600 [
3960.758209] Call Trace:
[ 3960.758219] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758226] [814e0048] ? hub_suspend+0xf8/0x130
[ 3960.758232] [814f0024] ? usbdev_do_ioctl+0x194/0x1000
[ 3960.758238] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758244] [8108ba01] ? get_parent_ip+0x11/0x50
[ 3960.758250] [8108d6cd] ? sub_preempt_count+0x9d/0xd0
[ 3960.758257] [815c02d2] ? hdpvr_probe+0x6c2/0xa30
The backtrace isn't valid, making this a bit harder to debug. Making compiling
the kernel with debug symbols would help here. Could you also please enable
lockdep (CONFIG_LOCKDEP=y) if not done already ?
[ 3960.758264] [817f8e84] schedule+0x24/0x70
[ 3960.758269] [817f9363] schedule_preempt_disabled+0x13/0x20
[ 3960.758275] [817f77c7] mutex_lock_nested+0x1a7/0x420
[ 3960.758281] [815c62d2] ? uvc_queue_enable+0x32/0xc0
[ 3960.758287] [815c62d2] uvc_queue_enable+0x32/0xc0
[ 3960.758292] [815c941f] uvc_video_enable+0x12f/0x180
[ 3960.758298] [815c7b55] uvc_v4l2_do_ioctl+0x555/0x1190
[ 3960.758304] [816c5668] ? sock_update_classid+0xa8/0x120
[ 3960.758310] [816c1d7e] ? sock_sendmsg+0xee/0x120
[ 3960.758316] [81561996] video_usercopy+0x186/0x4c0
[ 3960.758322] [815c7600] ? uvc_v4l2_set_streamparm+0x190/0x190
[ 3960.758327] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758333] [810a559f] ? lock_release+0xff/0x210
[ 3960.758338] [8108ba01] ? get_parent_ip+0x11/0x50
[ 3960.758344] [815c6bc4] uvc_v4l2_ioctl+0x24/0x70
[ 3960.758349] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758740] [8116e474] ? fsnotify+0x84/0x360
[ 3960.758745] [81560850] v4l2_ioctl+0xb0/0x180
[ 3960.758751] [81145213] do_vfs_ioctl+0x93/0x500
[ 3960.758756] [810a559f] ? lock_release+0xff/0x210
[ 3960.758762] [81134ba7] ? fget_light+0xd7/0x140
[ 3960.758768] [81134b0b] ? fget_light+0x3b/0x140
[ 3960.758773] [811456ca] sys_ioctl+0x4a/0x80
[ 3960.758778] [817fb0f9] system_call_fastpath+0x16/0x1b
[ 3960.758784] 1 lock held by motion/7776:
[ 3960.758788] #0: (queue-mutex){..}, at: [815c62d2]
It looks like the driver tries to take the lock queue-mutex lock a second
time. I don't see any code path that could lead to that.
--
Regards,
Laurent Pinchart
--
To unsubscribe from this list: send the line unsubscribe linux-media in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
[ 3960.758784] 1 lock held by motion/7776: [ 3960.758788] #0: (queue-mutex){......}, at: [ffffffff815c62d2] uvc_queue_enable+0x32/0xc0
Hi,
I'm using a webcam (logitech) supported by the uvcvideo module to capture video.
Previously once in a while I would get the uvcvideo: Failed to resubmit video
URB (-27)., but the grabbing continued without a problem.
Now the video grabbing program (motion) seems to lock due to some nested lock
if i interpret it right.
Additional problem is that i don't really know what kernel version was still
OK, so can't help with that info.
This is on a vanilla 3.4 RC kernel latest commit:
c629eaf8392b676b4f83c3dc344e66402bfeec92
--
Sander
[ 3696.753490] ehci_hcd :09:00.1: request 880016091400 would overflow
(3923+31 = 3936)
[ 3696.753494] uvcvideo: Failed to resubmit video URB (-27).
[ 3696.753563] ehci_hcd :09:00.1: request 880016091800 would overflow
(3922+31 = 3936)
[ 3696.753566] uvcvideo: Failed to resubmit video URB (-27).
[ 3696.753609] ehci_hcd :09:00.1: request 880016090800 would overflow
(3922+31 = 3936)
[ 3696.753611] uvcvideo: Failed to resubmit video URB (-27).
[ 3696.753645] ehci_hcd :09:00.1: request 880016090c00 would overflow
(3922+31 = 3936)
[ 3696.753647] uvcvideo: Failed to resubmit video URB (-27).
[ 3696.753656] ehci_hcd :09:00.1: request 880016091000 would overflow
(3922+31 = 3936)
[ 3696.753657] uvcvideo: Failed to resubmit video URB (-27).
[ 3960.758154] INFO: task motion:7776 blocked for more than 120 seconds.
[ 3960.758168] echo 0 /proc/sys/kernel/hung_task_timeout_secs disables this
message.
[ 3960.758174] motion D 0201 0 7776 1 0x
[ 3960.758183] 8800239d9b68 0216 eaa50018
810a451b
[ 3960.758192] 88002392cf60 00012600 8800239d9fd8
8800239d8010
[ 3960.758200] 00012600 00012600 8800239d9fd8
00012600
[ 3960.758209] Call Trace:
[ 3960.758219] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758226] [814e0048] ? hub_suspend+0xf8/0x130
[ 3960.758232] [814f0024] ? usbdev_do_ioctl+0x194/0x1000
[ 3960.758238] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758244] [8108ba01] ? get_parent_ip+0x11/0x50
[ 3960.758250] [8108d6cd] ? sub_preempt_count+0x9d/0xd0
[ 3960.758257] [815c02d2] ? hdpvr_probe+0x6c2/0xa30
[ 3960.758264] [817f8e84] schedule+0x24/0x70
[ 3960.758269] [817f9363] schedule_preempt_disabled+0x13/0x20
[ 3960.758275] [817f77c7] mutex_lock_nested+0x1a7/0x420
[ 3960.758281] [815c62d2] ? uvc_queue_enable+0x32/0xc0
[ 3960.758287] [815c62d2] uvc_queue_enable+0x32/0xc0
[ 3960.758292] [815c941f] uvc_video_enable+0x12f/0x180
[ 3960.758298] [815c7b55] uvc_v4l2_do_ioctl+0x555/0x1190
[ 3960.758304] [816c5668] ? sock_update_classid+0xa8/0x120
[ 3960.758310] [816c1d7e] ? sock_sendmsg+0xee/0x120
[ 3960.758316] [81561996] video_usercopy+0x186/0x4c0
[ 3960.758322] [815c7600] ? uvc_v4l2_set_streamparm+0x190/0x190
[ 3960.758327] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758333] [810a559f] ? lock_release+0xff/0x210
[ 3960.758338] [8108ba01] ? get_parent_ip+0x11/0x50
[ 3960.758344] [815c6bc4] uvc_v4l2_ioctl+0x24/0x70
[ 3960.758349] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 3960.758740] [8116e474] ? fsnotify+0x84/0x360
[ 3960.758745] [81560850] v4l2_ioctl+0xb0/0x180
[ 3960.758751] [81145213] do_vfs_ioctl+0x93/0x500
[ 3960.758756] [810a559f] ? lock_release+0xff/0x210
[ 3960.758762] [81134ba7] ? fget_light+0xd7/0x140
[ 3960.758768] [81134b0b] ? fget_light+0x3b/0x140
[ 3960.758773] [811456ca] sys_ioctl+0x4a/0x80
[ 3960.758778] [817fb0f9] system_call_fastpath+0x16/0x1b
[ 3960.758784] 1 lock held by motion/7776:
[ 3960.758788] #0: (queue-mutex){..}, at: [815c62d2]
uvc_queue_enable+0x32/0xc0
[ 4080.758504] INFO: task motion:7776 blocked for more than 120 seconds.
[ 4080.758518] echo 0 /proc/sys/kernel/hung_task_timeout_secs disables this
message.
[ 4080.758524] motion D 0201 0 7776 1 0x
[ 4080.758532] 8800239d9b68 0216 eaa50018
810a451b
[ 4080.758540] 88002392cf60 00012600 8800239d9fd8
8800239d8010
[ 4080.758547] 00012600 00012600 8800239d9fd8
00012600
[ 4080.758555] Call Trace:
[ 4080.758564] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 4080.758570] [814e0048] ? hub_suspend+0xf8/0x130
[ 4080.758576] [814f0024] ? usbdev_do_ioctl+0x194/0x1000
[ 4080.758581] [810a451b] ? __lock_acquire+0x5b/0xc00
[ 4080.758587] [8108ba01] ? get_parent_ip+0x11/0x50
[ 4080.758592] [8108d6cd] ? sub_preempt_count+0x9d/0xd0
[ 4080.758597] [815c02d2] ? hdpvr_probe+0x6c2/0xa30
[ 4080.758603] [817f8e84] schedule+0x24/0x70
[ 4080.758608] [817f9363
