Re: block: deadlock between disk_block_events() and blk_execute_rq()

From: Bart Van Assche
Date: Sun Jan 01 2012 - 12:35:44 EST


On Sun, Jan 1, 2012 at 5:22 PM, Bart Van Assche <bvanassche@xxxxxxx> wrote:
> In a workload that involves a lot of scsi_remove_hosts() calls (srp-ha
> patch set stress test) I get the call stack below after about 30 to 50
> iterations. Is this a known issue ? Does this indicate a race
> condition in the block layer ? I can trigger this issue not only with
> 3.2-rc7 but also with 3.1.6. I haven't tried any other kernel versions
> yet.

(replying to my own e-mail)

By the way, I've been able to trigger a deadlock between
disk_block_events() and blk_execute_rq() with the same workload. I'm
not sure though whether this is an independent issue or a consequence
of the aforementioned warning. This issue is also reproducible with
both 3.1.6 and 3.2-rc7. See below for the two call stacks of the tasks
involved in the deadlock. Any feedback is welcome.

(1)

INFO: task kworker/1:2:9322 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:2 D ffff880150603d80 0 9322 2 0x00000000
ffff88015071f8d0 0000000000000046 0000000050603d80 0000000000000046
0000000000000005 ffff88015071ffd8 ffff88015071ffd8 ffff88015071ffd8
ffff880150603d80 ffff88015071ffd8 ffff88015071ffd8 ffff88015071e000
Call Trace:
[<ffffffff813dac8f>] schedule+0x3f/0x60
[<ffffffff813db14d>] schedule_timeout+0x1bd/0x2d0
[<ffffffff813dd587>] ? _raw_spin_lock_irq+0x17/0x60
[<ffffffff813dddd0>] ? _raw_spin_unlock_irq+0x30/0x50
[<ffffffff81082fad>] ? trace_hardirqs_on_caller+0x11d/0x1b0
[<ffffffff813da2c0>] wait_for_common+0x120/0x170
[<ffffffff8103d890>] ? try_to_wake_up+0x2b0/0x2b0
[<ffffffff81082fad>] ? trace_hardirqs_on_caller+0x11d/0x1b0
[<ffffffff813da3ed>] wait_for_completion+0x1d/0x20
[<ffffffff810624c2>] wait_on_cpu_work+0xf2/0x130
[<ffffffff81061170>] ? do_work_for_cpu+0x30/0x30
[<ffffffff810631de>] wait_on_work+0xfe/0x150
[<ffffffff810630e0>] ? rescuer_thread+0x230/0x230
[<ffffffff813dd5ec>] ? _raw_spin_lock_irqsave+0x1c/0x60
[<ffffffff81063383>] __cancel_work_timer+0x83/0x130
[<ffffffff81063442>] cancel_delayed_work_sync+0x12/0x20
[<ffffffff811e13a3>] disk_block_events+0xa3/0xb0
[<ffffffff811e13da>] del_gendisk+0x2a/0x1f0
[<ffffffff81297ca7>] ? put_device+0x17/0x20
[<ffffffff81298743>] ? device_del+0x173/0x1b0
[<ffffffffa015181d>] sd_remove+0x6d/0xc0 [sd_mod]
[<ffffffff8129bb9c>] __device_release_driver+0x7c/0xe0
[<ffffffff8129be8f>] device_release_driver+0x2f/0x50
[<ffffffff8129b617>] bus_remove_device+0x87/0x100
[<ffffffff812986fd>] device_del+0x12d/0x1b0
[<ffffffffa003d545>] __scsi_remove_device+0xc5/0xd0 [scsi_mod]
[<ffffffffa003c03f>] scsi_forget_host+0x6f/0x80 [scsi_mod]
[<ffffffffa00316ca>] scsi_remove_host+0x7a/0x130 [scsi_mod]
[<ffffffffa03a53b5>] srp_remove_target+0xe5/0x140 [ib_srp]
[<ffffffffa03a55f4>] srp_remove_work+0x64/0x90 [ib_srp]
[<ffffffff81062ae8>] process_one_work+0x198/0x520
[<ffffffff81062a79>] ? process_one_work+0x129/0x520
[<ffffffffa03a5590>] ? srp_remove_one+0x180/0x180 [ib_srp]
[<ffffffff810647ca>] worker_thread+0x16a/0x350
[<ffffffff81064660>] ? manage_workers+0x250/0x250
[<ffffffff81069776>] kthread+0x96/0xa0
[<ffffffff813e7ff4>] kernel_thread_helper+0x4/0x10
[<ffffffff813de21d>] ? retint_restore_args+0xe/0xe
[<ffffffff810696e0>] ? __init_kthread_worker+0x70/0x70
[<ffffffff813e7ff0>] ? gs_change+0xb/0xb
5 locks held by kworker/1:2/9322:
#0: (events_long){.+.+.+}, at: [<ffffffff81062a79>]
process_one_work+0x129/0x520
#1: ((&target->remove_work)){+.+.+.}, at: [<ffffffff81062a79>]
process_one_work+0x129/0x520
#2: (&shost->scan_mutex){+.+.+.}, at: [<ffffffffa0031676>]
scsi_remove_host+0x26/0x130 [scsi_mod]
#3: (&__lockdep_no_validate__){......}, at: [<ffffffff8129be87>]
device_release_driver+0x27/0x50
#4: (&ev->block_mutex){+.+...}, at: [<ffffffff811e1342>]
disk_block_events+0x42/0xb0

(2) (obtained via sysrq)

kworker/1:4 D ffff8801bfc91bc0 0 4547 2 0x00000000
ffff8801a4083900 0000000000000046 ffff8801a7825c40 0000000000000006
0000000000000001 ffff8801a4083fd8 ffff8801a4083fd8 ffff8801a4083fd8
ffff8801a7825c40 ffff8801a4083fd8 ffff8801a4083fd8 ffff8801a4082000
Call Trace:
[<ffffffff81082fad>] ? trace_hardirqs_on_caller+0x11d/0x1b0
[<ffffffff813dac8f>] schedule+0x3f/0x60
[<ffffffff813db0f7>] schedule_timeout+0x167/0x2d0
[<ffffffff810555c0>] ? del_timer+0xf0/0xf0
[<ffffffff813da2c0>] wait_for_common+0x120/0x170
[<ffffffff8103d890>] ? try_to_wake_up+0x2b0/0x2b0
[<ffffffff813dddd0>] ? _raw_spin_unlock_irq+0x30/0x50
[<ffffffff813da3c3>] wait_for_completion_timeout+0x13/0x20
[<ffffffff811dc97b>] blk_execute_rq+0x10b/0x180
[<ffffffff811d75e9>] ? get_request_wait+0x29/0x1c0
[<ffffffffa0037fbe>] scsi_execute+0xee/0x180 [scsi_mod]
[<ffffffffa003823f>] scsi_execute_req+0xbf/0x130 [scsi_mod]
[<ffffffffa003834b>] scsi_test_unit_ready+0x9b/0x150 [scsi_mod]
[<ffffffffa01643ee>] sd_check_events+0x12e/0x1c0 [sd_mod]
[<ffffffff811df844>] disk_events_workfn+0x64/0x120
[<ffffffff81062ae8>] process_one_work+0x198/0x520
[<ffffffff81062a79>] ? process_one_work+0x129/0x520
[<ffffffff811df7e0>] ? __disk_unblock_events+0x110/0x110
[<ffffffff810647ca>] worker_thread+0x16a/0x350
[<ffffffff81064660>] ? manage_workers+0x250/0x250
[<ffffffff81069776>] kthread+0x96/0xa0
[<ffffffff813e7ff4>] kernel_thread_helper+0x4/0x10
[<ffffffff813de21d>] ? retint_restore_args+0xe/0xe
[<ffffffff810696e0>] ? __init_kthread_worker+0x70/0x70
[<ffffffff813e7ff0>] ? gs_change+0xb/0xb
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/