On 14-08-30 04:56 PM, Milan Broz wrote:
Hi,
I am using scsi_debug in cryptsetup testsuite and with recent 3.17-rc kernel
it deadlocks on rmmod of scsi_debug module.
For me even this simple reproducer causes deadlock:
modprobe scsi_debug dev_size_mb=16 sector_size=512 num_tgts=1
DEV="/dev/"$(grep -l -e scsi_debug /sys/block/*/device/model | cut -f4 -d /)
mkfs -t ext4 $DEV
rmmod scsi_debug
(adding small delay before rmmod obviously helps here)
So I used this slight variation for testing:
modprobe scsi_debug dev_size_mb=16 sector_size=512 num_tgts=1 num_parts=1
DEV="/dev/"$(grep -l -e scsi_debug /sys/block/*/device/model | cut -f4 -d /)"1"
echo "mkfs -t ext4 ${DEV}"
mkfs -t ext4 ${DEV}
sleep 0.1
rmmod scsi_debug
Bisect tracked it to commit
commit cbf67842c3d9e7af8ccc031332b79e88d9cca592
Author: Douglas Gilbert <dgilbert@xxxxxxxxxxxx>
Date: Sat Jul 26 11:55:35 2014 -0400
scsi_debug: support scsi-mq, queues and locks
I guess that with introducing mq the del_timer_sync() must not be called
with acquired queued_arr_lock.
(to me it looks like situation described in comment before
del_timer_sync() in kernel/time/timer.c...)
Looks like something a lawyer would write.
Here is the log (running on vmware VM and i686 arch):
[ 67.916472] scsi_debug: host protection
[ 67.916483] scsi host3: scsi_debug, version 1.84 [20140706], dev_size_mb=16, opts=0x0
[ 67.917446] scsi 3:0:0:0: Direct-Access Linux scsi_debug 0184 PQ: 0 ANSI: 5
[ 67.920539] sd 3:0:0:0: Attached scsi generic sg8 type 0
[ 67.940542] sd 3:0:0:0: [sdh] 32768 512-byte logical blocks: (16.7 MB/16.0 MiB)
[ 67.940548] sd 3:0:0:0: [sdh] 4096-byte physical blocks
[ 67.950705] sd 3:0:0:0: [sdh] Write Protect is off
[ 67.950715] sd 3:0:0:0: [sdh] Mode Sense: 73 00 10 08
[ 67.970514] sd 3:0:0:0: [sdh] Write cache: enabled, read cache: enabled, supports DPO and FUA
[ 68.040566] sdh: unknown partition table
[ 68.090618] sd 3:0:0:0: [sdh] Attached SCSI disk
[ 68.799699] sdh: unknown partition table
[ 69.072314]
[ 69.072387] ======================================================
[ 69.072433] [ INFO: possible circular locking dependency detected ]
[ 69.072487] 3.17.0-rc2+ #80 Not tainted
[ 69.072518] -------------------------------------------------------
[ 69.072560] rmmod/2890 is trying to acquire lock:
[ 69.072595] ((sqcp->cmnd_timerp)){+.-...}, at: [<c10846c0>] del_timer_sync+0x0/0xb0
[ 69.072704]
[ 69.072704] but task is already holding lock:
[ 69.072743] (queued_arr_lock){..-...}, at: [<e1271887>] stop_all_queued+0x17/0xc0 [scsi_debug]
[ 69.072852]
[ 69.072852] which lock already depends on the new lock.
[ 69.072852]
<snip>
[ 69.075321] Possible unsafe locking scenario:
[ 69.075321]
[ 69.075380] CPU0 CPU1
[ 69.075424] ---- ----
[ 69.075468] lock(queued_arr_lock);
[ 69.075534] lock((sqcp->cmnd_timerp));
[ 69.075613] lock(queued_arr_lock);
[ 69.075690] lock((sqcp->cmnd_timerp));
[ 69.075758]
[ 69.075758] *** DEADLOCK ***
Interesting analysis, somewhat confusing because cmnd_timerp
is a pointer. Also my guess is the sqcp pointers in the
two threads were different.
Anyway the attached patch removes the lock(queued_arr_lock)
from around the del_timer calls. Could you try it and report
back.
Doug Gilbert
--- a/drivers/scsi/scsi_debug.c 2014-08-26 13:24:51.646948507 -0400
+++ b/drivers/scsi/scsi_debug.c 2014-08-30 18:04:54.589226679 -0400
@@ -2743,6 +2743,13 @@ static int stop_queued_cmnd(struct scsi_
if (test_bit(k, queued_in_use_bm)) {
sqcp = &queued_arr[k];
if (cmnd == sqcp->a_cmnd) {
+ devip = (struct sdebug_dev_info *)
+ cmnd->device->hostdata;
+ if (devip)
+ atomic_dec(&devip->num_in_q);
+ sqcp->a_cmnd = NULL;
+ spin_unlock_irqrestore(&queued_arr_lock,
+ iflags);
if (scsi_debug_ndelay > 0) {
if (sqcp->sd_hrtp)
hrtimer_cancel(
@@ -2755,18 +2762,13 @@ static int stop_queued_cmnd(struct scsi_
if (sqcp->tletp)
tasklet_kill(sqcp->tletp);
}
- __clear_bit(k, queued_in_use_bm);
- devip = (struct sdebug_dev_info *)
- cmnd->device->hostdata;
- if (devip)
- atomic_dec(&devip->num_in_q);
- sqcp->a_cmnd = NULL;
- break;
+ clear_bit(k, queued_in_use_bm);
+ return 1;
}
}
}
spin_unlock_irqrestore(&queued_arr_lock, iflags);
- return (k < qmax) ? 1 : 0;
+ return 0;
}
/* Deletes (stops) timers or tasklets of all queued commands */
@@ -2782,6 +2784,13 @@ static void stop_all_queued(void)
if (test_bit(k, queued_in_use_bm)) {
sqcp = &queued_arr[k];
if (sqcp->a_cmnd) {
+ devip = (struct sdebug_dev_info *)
+ sqcp->a_cmnd->device->hostdata;
+ if (devip)
+ atomic_dec(&devip->num_in_q);
+ sqcp->a_cmnd = NULL;
+ spin_unlock_irqrestore(&queued_arr_lock,
+ iflags);
if (scsi_debug_ndelay > 0) {
if (sqcp->sd_hrtp)
hrtimer_cancel(
@@ -2794,12 +2803,8 @@ static void stop_all_queued(void)
if (sqcp->tletp)
tasklet_kill(sqcp->tletp);
}
- __clear_bit(k, queued_in_use_bm);
- devip = (struct sdebug_dev_info *)
- sqcp->a_cmnd->device->hostdata;
- if (devip)
- atomic_dec(&devip->num_in_q);
- sqcp->a_cmnd = NULL;
+ clear_bit(k, queued_in_use_bm);
+ spin_lock_irqsave(&queued_arr_lock, iflags);
}
}
}
