Re: hdpvr mutex deadlock on kernel 5.1.x

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Keith,

On 6/18/19 6:17 AM, Keith Pyle wrote:
> We made the suggested change, compiled, installed, and rebooted. There was some progress - test 2 (turning the HD-PVR off) no longer produces a splat.  Test 1 (start capture) and test 3 (run capture
> and trigger HD-PVR to stop streaming) both still produce a traceback (see below).  Test 3 also still results in the unkillable process.

Try the following patch. Test 2 was caused by locking when it shouldn't, test 3 was caused by not
locking when it should :-) and I think test 1 was caused by locking when it is not allowed.

Let me know if this works!

Regards,

	Hans

Signed-off-by: Hans Verkuil <hverkuil-cisco@xxxxxxxxx>
---
diff --git a/drivers/media/usb/hdpvr/hdpvr-video.c b/drivers/media/usb/hdpvr/hdpvr-video.c
index 3786ddcc0d18..4ba134a3bc25 100644
--- a/drivers/media/usb/hdpvr/hdpvr-video.c
+++ b/drivers/media/usb/hdpvr/hdpvr-video.c
@@ -435,7 +435,7 @@ static ssize_t hdpvr_read(struct file *file, char __user *buffer, size_t count,
 	/* wait for the first buffer */
 	if (!(file->f_flags & O_NONBLOCK)) {
 		if (wait_event_interruptible(dev->wait_data,
-					     hdpvr_get_next_buffer(dev)))
+					     !list_empty_careful(&dev->rec_buff_list)))
 			return -ERESTARTSYS;
 	}

@@ -463,7 +463,9 @@ static ssize_t hdpvr_read(struct file *file, char __user *buffer, size_t count,
 			if (!err) {
 				v4l2_dbg(MSG_INFO, hdpvr_debug, &dev->v4l2_dev,
 					"timeout: restart streaming\n");
+				mutex_lock(&dev->io_mutex);
 				hdpvr_stop_streaming(dev);
+				mutex_unlock(&dev->io_mutex);
 				msecs_to_jiffies(4000);
 				err = hdpvr_start_streaming(dev);
 				if (err) {
@@ -1124,9 +1126,7 @@ static void hdpvr_device_release(struct video_device *vdev)
 	struct hdpvr_device *dev = video_get_drvdata(vdev);

 	hdpvr_delete(dev);
-	mutex_lock(&dev->io_mutex);
 	flush_work(&dev->worker);
-	mutex_unlock(&dev->io_mutex);

 	v4l2_device_unregister(&dev->v4l2_dev);
 	v4l2_ctrl_handler_free(&dev->hdl);



> 
> --- test 1 trace
> 
> [  286.987001] ------------[ cut here ]------------
> [  286.987006] do not call blocking ops when !TASK_RUNNING; state=1 set at [<0000000007f37036>] prepare_to_wait_event+0xa7/0xe5
> [  286.987009] WARNING: CPU: 1 PID: 2768 at __might_sleep+0x52/0x65
> [  286.987010] Modules linked in: x86_pkg_temp_thermal hdpvr efivarfs
> [  286.987013] CPU: 1 PID: 2768 Comm: cat_hdpvr Not tainted 5.1.10-ld+ #4
> [  286.987014] Hardware name: MSI MS-7A72/Z270 PC MATE (MS-7A72), BIOS 1.60 07/11/2017
> [  286.987015] RIP: 0010:__might_sleep+0x52/0x65
> [  286.987016] Code: 80 3d e7 98 43 01 00 75 23 48 8b 90 38 21 00 00 48 c7 c7 ce 46 11 b7 c6 05 d0 98 43 01 01 48 8b 70 10 48 89 d1 e8 56 b2 fd ff <0f> 0b 44 89 e2 89 ee 48 89 df 5b 5d 41 5c e9 de fd
> ff ff 83 fe 07
> [  286.987017] RSP: 0018:ffffa24480677d30 EFLAGS: 00010282
> [  286.987018] RAX: 0000000000000070 RBX: ffffffffb71164a0 RCX: 0000000000000007
> [  286.987019] RDX: 0000000000000000 RSI: 0000000000000006 RDI: ffff9f1c5ea95610
> [  286.987020] RBP: 000000000000038c R08: 0000000000000001 R09: 000000000000000c
> [  286.987020] R10: ffffa24480677e18 R11: 0000012dadcb5f34 R12: 0000000000000000
> [  286.987021] R13: 0000000000002000 R14: 0000000000000002 R15: 0000000000000000
> [  286.987022] FS:  00007f8130e71540(0000) GS:ffff9f1c5ea80000(0000) knlGS:0000000000000000
> [  286.987023] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  286.987024] CR2: 00007ffc0fb650a0 CR3: 000000043f3c6002 CR4: 00000000001606e0
> [  286.987025] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [  286.987025] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [  286.987026] Call Trace:
> [  286.987028]  __mutex_lock+0x47/0x7ac
> [  286.987031]  ? hdpvr_get_next_buffer+0x16/0x4a [hdpvr]
> [  286.987032]  ? find_held_lock+0x2b/0x6e
> [  286.987033]  ? prepare_to_wait_event+0xdc/0xe5
> [  286.987034]  ? _raw_spin_unlock_irqrestore+0x37/0x4a
> [  286.987036]  ? hdpvr_get_next_buffer+0x16/0x4a [hdpvr]
> [  286.987037]  hdpvr_get_next_buffer+0x16/0x4a [hdpvr]
> [  286.987038]  hdpvr_read+0x174/0x450 [hdpvr]
> [  286.987040]  ? _raw_spin_unlock_irq+0x24/0x35
> [  286.987041]  ? lockdep_hardirqs_on+0x168/0x183
> [  286.987042]  ? wait_woken+0x86/0x86
> [  286.987044]  v4l2_read+0x38/0x7a
> [  286.987045]  vfs_read+0xad/0x136
> [  286.987047]  ksys_read+0x53/0x95
> [  286.987048]  do_syscall_64+0x52/0x155
> [  286.987050]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [  286.987051] RIP: 0033:0x7f8130d97005
> [  286.987052] Code: 00 00 0f 1f 00 48 83 ec 38 64 48 8b 04 25 28 00 00 00 48 89 44 24 28 31 c0 48 8d 05 35 85 0d 00 8b 00 85 c0 75 27 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 63 48 8b 4c 24 28 64 48 33 0c
> 25 28 00 00 00
> [  286.987052] RSP: 002b:00007ffc0fb2aea0 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
> [  286.987053] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f8130d97005
> [  286.987054] RDX: 0000000000002000 RSI: 0000555c13090080 RDI: 0000000000000003
> [  286.987055] RBP: 00007ffc0fb2af70 R08: 0000000000000000 R09: 0000000000000000
> [  286.987056] R10: 0000000000000000 R11: 0000000000000246 R12: 0000555c13090080
> [  286.987056] R13: 0000000000000000 R14: 00007ffc0fb2d165 R15: 0000000000000000
> [  286.987058] irq event stamp: 1644
> [  286.987059] hardirqs last  enabled at (1643): [<ffffffffb614832b>] console_unlock+0x493/0x4da
> [  286.987060] hardirqs last disabled at (1644): [<ffffffffb6001460>] trace_hardirqs_off_thunk+0x1a/0x1c
> [  286.987062] softirqs last  enabled at (1246): [<ffffffffb6c00376>] __do_softirq+0x376/0x3b2
> [  286.987063] softirqs last disabled at (1237): [<ffffffffb60f1ea2>] irq_exit+0x4e/0x9d
> [  286.987064] ---[ end trace 64a925bcd732953e ]---
> 
> --- test 3 trace
> 
> [ 7933.630215] ------------[ cut here ]------------
> [ 7933.630218] DEBUG_LOCKS_WARN_ON(depth <= 0)
> [ 7933.630224] WARNING: CPU: 0 PID: 14570 at lock_release+0x147/0x230
> [ 7933.630226] Modules linked in: x86_pkg_temp_thermal hdpvr efivarfs
> [ 7933.630229] CPU: 0 PID: 14570 Comm: cat_hdpvr Tainted: G W         5.1.10-ld+ #4
> [ 7933.630230] Hardware name: MSI MS-7A72/Z270 PC MATE (MS-7A72), BIOS 1.60 07/11/2017
> [ 7933.630232] RIP: 0010:lock_release+0x147/0x230
> [ 7933.630233] Code: 01 5f 04 75 29 e8 35 e7 25 00 85 c0 74 3b 83 3d 18 1a 42 01 00 75 32 48 c7 c6 a3 78 11 b7 48 c7 c7 2f 44 10 b7 e8 a9 10 fb ff <0f> 0b eb 1b 48 8d 4c 24 04 44 89 fa 48 89 ee 48 89
> df e8 87 c4 ff
> [ 7933.630234] RSP: 0018:ffffa24481c6fd88 EFLAGS: 00010082
> [ 7933.630236] RAX: 000000000000001f RBX: ffff9f1c28ea8000 RCX: 0000000000000000
> [ 7933.630237] RDX: ffffffffb6149356 RSI: 0000000000000001 RDI: ffffffffb6149368
> [ 7933.630238] RBP: ffff9f1c2c838820 R08: ffffffffba72cee0 R09: 000000000000001f
> [ 7933.630239] R10: 0000000000000001 R11: 00001e633eb23eea R12: ffffffffc0366de1
> [ 7933.630240] R13: 0000000000000246 R14: ffff9f1c28500700 R15: 0000000000000000
> [ 7933.630241] FS:  00007fd61de88540(0000) GS:ffff9f1c5ea00000(0000) knlGS:0000000000000000
> [ 7933.630242] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 7933.630243] CR2: 0000000007af0000 CR3: 0000000428622002 CR4: 00000000001606f0
> [ 7933.630244] DR0: 0000000037e28bcc DR1: 0000000000000000 DR2: 0000000000000000
> [ 7933.630245] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
> [ 7933.630245] Call Trace:
> [ 7933.630249]  __mutex_unlock_slowpath+0x34/0x1e9
> [ 7933.630252]  hdpvr_stop_streaming+0x78/0x169 [hdpvr]
> [ 7933.630254]  hdpvr_read+0x33c/0x450 [hdpvr]
> [ 7933.630256]  ? lockdep_hardirqs_on+0x168/0x183
> [ 7933.630258]  ? wait_woken+0x86/0x86
> [ 7933.630260]  v4l2_read+0x38/0x7a
> [ 7933.630262]  vfs_read+0xad/0x136
> [ 7933.630264]  ksys_read+0x53/0x95
> [ 7933.630266]  do_syscall_64+0x52/0x155
> [ 7933.630268]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [ 7933.630270] RIP: 0033:0x7fd61ddae005
> [ 7933.630271] Code: 00 00 0f 1f 00 48 83 ec 38 64 48 8b 04 25 28 00 00 00 48 89 44 24 28 31 c0 48 8d 05 35 85 0d 00 8b 00 85 c0 75 27 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 63 48 8b 4c 24 28 64 48 33 0c
> 25 28 00 00 00
> [ 7933.630272] RSP: 002b:00007fffdb949a60 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
> [ 7933.630274] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007fd61ddae005
> [ 7933.630275] RDX: 0000000000002000 RSI: 000055caa2856080 RDI: 0000000000000003
> [ 7933.630275] RBP: 00007fffdb949b30 R08: 0000000000000000 R09: 0000000000000000
> [ 7933.630276] R10: 0000000000000000 R11: 0000000000000246 R12: 000055caa2856080
> [ 7933.630277] R13: 0000000000000000 R14: 00007fffdb94a156 R15: 0000000000002000
> [ 7933.630279] irq event stamp: 30970489
> [ 7933.630281] hardirqs last  enabled at (30970489): [<ffffffffb620e6eb>] kfree+0x196/0x217
> [ 7933.630283] hardirqs last disabled at (30970488): [<ffffffffb620e6c8>] kfree+0x173/0x217
> [ 7933.630284] softirqs last  enabled at (30970034): [<ffffffffb6c00376>] __do_softirq+0x376/0x3b2
> [ 7933.630286] softirqs last disabled at (30970027): [<ffffffffb60f1ea2>] irq_exit+0x4e/0x9d
> [ 7933.630287] ---[ end trace 64a925bcd732953f ]---
> 




[Index of Archives]     [Linux Input]     [Video for Linux]     [Gstreamer Embedded]     [Mplayer Users]     [Linux USB Devel]     [Linux Audio Users]     [Linux Kernel]     [Linux SCSI]     [Yosemite Backpacking]

  Powered by Linux